Closed Bug 1401366 Opened 8 years ago Closed 8 years ago

Intermittent application crashed [@ mozilla::dom::HTMLMediaElement::ShutdownObserver::Observe(nsISupports *,char const *,char16_t const *)]

Categories

(Core :: Audio/Video: Playback, defect, P5)

defect

Tracking

()

RESOLVED FIXED
mozilla57
Tracking Status
firefox-esr52 --- unaffected
firefox55 --- unaffected
firefox56 --- unaffected
firefox57 --- fixed

People

(Reporter: intermittent-bug-filer, Assigned: jwwang)

Details

(Keywords: crash, intermittent-failure)

Crash Data

Attachments

(2 files)

Filed by: archaeopteryx [at] coole-files.de https://treeherder.mozilla.org/logviewer.html#?job_id=132032192&repo=mozilla-inbound https://queue.taskcluster.net/v1/task/SuaM_R4gS626m-d7z6rBZQ/runs/0/artifacts/public/logs/live_backing.log 17:42:08 INFO - 777 INFO TEST-START | dom/xul/templates/tests/chrome/test_tmpl_xmlquerywithsortotherfield.xul 17:42:08 INFO - GECKO(5088) | MEMORY STAT | vsize 1892MB | vsizeMaxContiguous 132050192MB | residentFast 387MB | heapAllocated 176MB 17:42:08 INFO - 778 INFO TEST-OK | dom/xul/templates/tests/chrome/test_tmpl_xmlquerywithsortotherfield.xul | took 50ms 17:42:08 INFO - 779 INFO TEST-START | Shutdown 17:42:08 INFO - 780 INFO Passed: 523 17:42:08 INFO - 781 INFO Failed: 0 17:42:08 INFO - 782 INFO Todo: 77 17:42:08 INFO - 783 INFO Mode: non-e10s 17:42:08 INFO - 784 INFO Slowest: 1049ms - chrome://mochitests/content/chrome/dom/xul/templates/tests/chrome/test_bug329335.xul 17:42:08 INFO - 785 INFO SimpleTest FINISHED 17:42:08 INFO - 786 INFO TEST-INFO | Ran 1 Loops 17:42:08 INFO - 787 INFO SimpleTest FINISHED 17:42:08 INFO - GECKO(5088) | *** UTM:SVC TimerManager:registerTimer called after profile-before-change notification. Ignoring timer registration for id: telemetry_modules_ping 17:42:09 INFO - TEST-INFO | Main app process: exit 1 17:42:09 INFO - Buffered messages finished 17:42:09 ERROR - 788 ERROR TEST-UNEXPECTED-FAIL | dom/xul/templates/tests/chrome/test_tmpl_xmlquerywithsortotherfield.xul | application terminated with exit code 1 17:42:09 INFO - runtests.py | Application ran for: 0:00:16.689000 17:42:09 INFO - zombiecheck | Reading PID log: c:\users\genericworker\appdata\local\temp\tmpiloqfopidlog 17:42:09 INFO - mozcrash Downloading symbols from: https://queue.taskcluster.net/v1/task/e6HxmsIIShi78PfJvkk3cA/artifacts/public/build/target.crashreporter-symbols.zip 17:42:21 INFO - mozcrash Copy/paste: Z:\task_1505842326\build\win32-minidump_stackwalk.exe c:\users\genericworker\appdata\local\temp\tmpsprhoj.mozrunner\minidumps\16689e2f-1691-4c9c-9ff4-579592569a41.dmp c:\users\genericworker\appdata\local\temp\tmpohhgne 17:42:28 INFO - mozcrash Saved minidump as Z:\task_1505842326\build\blobber_upload_dir\16689e2f-1691-4c9c-9ff4-579592569a41.dmp 17:42:28 INFO - mozcrash Saved app info as Z:\task_1505842326\build\blobber_upload_dir\16689e2f-1691-4c9c-9ff4-579592569a41.extra 17:42:28 WARNING - PROCESS-CRASH | dom/xul/templates/tests/chrome/test_tmpl_xmlquerywithsortotherfield.xul | application crashed [@ mozilla::dom::HTMLMediaElement::ShutdownObserver::Observe(nsISupports *,char const *,char16_t const *)] 17:42:28 INFO - Crash dump filename: c:\users\genericworker\appdata\local\temp\tmpsprhoj.mozrunner\minidumps\16689e2f-1691-4c9c-9ff4-579592569a41.dmp 17:42:28 INFO - Operating system: Windows NT 17:42:28 INFO - 10.0.15063 17:42:28 INFO - CPU: amd64 17:42:28 INFO - family 6 model 63 stepping 2 17:42:28 INFO - 8 CPUs 17:42:28 INFO - GPU: UNKNOWN 17:42:28 INFO - Crash reason: EXCEPTION_BREAKPOINT 17:42:28 INFO - Crash address: 0x7ffd93318b1b 17:42:28 INFO - Process uptime: 16 seconds 17:42:28 INFO - Thread 0 (crashed) 17:42:28 INFO - 0 xul.dll!mozilla::dom::HTMLMediaElement::ShutdownObserver::Observe(nsISupports *,char const *,char16_t const *) [HTMLMediaElement.cpp:5b0de4548020 : 3772 + 0x11] 17:42:28 INFO - rax = 0x00007ffdb7636d58 rdx = 0x00000207acdbc148 17:42:28 INFO - rcx = 0x00007ffd956c64c0 rbx = 0x000000000000012e 17:42:28 INFO - rsi = 0x0000000000000000 rdi = 0x000000000000012e 17:42:28 INFO - rbp = 0x00007ffd95323260 rsp = 0x0000004a1e7ff180 17:42:28 INFO - r8 = 0x00007ffd95323260 r9 = 0x0000000000000000 17:42:28 INFO - r10 = 0x00007ffd952d9d30 r11 = 0x00000207b729c000 17:42:28 INFO - r12 = 0x0000004a1e7ff488 r13 = 0x0000000080000000 17:42:28 INFO - r14 = 0x00000207acdbc148 r15 = 0x0000004a1e7ff460 17:42:28 INFO - rip = 0x00007ffd93318b1b 17:42:28 INFO - Found by: given as instruction pointer in context 17:42:28 INFO - 1 xul.dll!nsObserverList::NotifyObservers(nsISupports *,char const *,char16_t const *) [nsObserverList.cpp:5b0de4548020 : 112 + 0x1d] 17:42:28 INFO - rbx = 0x000000000000012e rbp = 0x00007ffd95323260 17:42:28 INFO - rsp = 0x0000004a1e7ff1b0 r12 = 0x0000004a1e7ff488 17:42:28 INFO - r13 = 0x0000000080000000 r14 = 0x00000207acdbc148 17:42:28 INFO - r15 = 0x0000004a1e7ff460 rip = 0x00007ffd92de6fc6 17:42:28 INFO - Found by: call frame info 17:42:28 INFO - 2 xul.dll!nsObserverService::NotifyObservers(nsISupports *,char const *,char16_t const *) [nsObserverService.cpp:5b0de4548020 : 296 + 0x11] 17:42:28 INFO - rbx = 0x000000000000012e rbp = 0x00007ffd95323260 17:42:28 INFO - rsp = 0x0000004a1e7ff1f0 r12 = 0x0000004a1e7ff488 17:42:28 INFO - r13 = 0x0000000080000000 r14 = 0x00000207acdbc148 17:42:28 INFO - r15 = 0x0000004a1e7ff460 rip = 0x00007ffd92de6e54 17:42:28 INFO - Found by: call frame info 17:42:28 INFO - 3 xul.dll!mozilla::ShutdownXPCOM(nsIServiceManager *) [XPCOMInit.cpp:5b0de4548020 : 877 + 0x17] 17:42:28 INFO - rbx = 0x000000000000012e rbp = 0x00007ffd95323260 17:42:28 INFO - rsp = 0x0000004a1e7ff270 r12 = 0x0000004a1e7ff488 17:42:28 INFO - r13 = 0x0000000080000000 r14 = 0x00000207acdbc148 17:42:28 INFO - r15 = 0x0000004a1e7ff460 rip = 0x00007ffd9300a3c0 17:42:28 INFO - Found by: call frame info 17:42:28 INFO - 4 xul.dll!ScopedXPCOMStartup::~ScopedXPCOMStartup() [nsAppRunner.cpp:5b0de4548020 : 1527 + 0x8] 17:42:28 INFO - rbx = 0x000000000000012e rbp = 0x00007ffd95323260 17:42:28 INFO - rsp = 0x0000004a1e7ff2d0 r12 = 0x0000004a1e7ff488 17:42:28 INFO - r13 = 0x0000000080000000 r14 = 0x00000207acdbc148 17:42:28 INFO - r15 = 0x0000004a1e7ff460 rip = 0x00007ffd92c3edef 17:42:28 INFO - Found by: call frame info 17:42:28 INFO - 5 xul.dll!mozilla::UniquePtr<ScopedXPCOMStartup,mozilla::DefaultDelete<ScopedXPCOMStartup> >::reset(ScopedXPCOMStartup *) [UniquePtr.h:5b0de4548020 : 345 + 0xe] 17:42:28 INFO - rbx = 0x000000000000012e rbp = 0x00007ffd95323260 17:42:28 INFO - rsp = 0x0000004a1e7ff300 r12 = 0x0000004a1e7ff488 17:42:28 INFO - r13 = 0x0000000080000000 r14 = 0x00000207acdbc148 17:42:28 INFO - r15 = 0x0000004a1e7ff460 rip = 0x00007ffd92c3ed6b 17:42:28 INFO - Found by: call frame info 17:42:28 INFO - 6 xul.dll!XREMain::XRE_main(int,char * * const,mozilla::BootstrapConfig const &) [nsAppRunner.cpp:5b0de4548020 : 4893 + 0xa] 17:42:28 INFO - rbx = 0x000000000000012e rbp = 0x00007ffd95323260 17:42:28 INFO - rsp = 0x0000004a1e7ff330 r12 = 0x0000004a1e7ff488 17:42:28 INFO - r13 = 0x0000000080000000 r14 = 0x00000207acdbc148 17:42:28 INFO - r15 = 0x0000004a1e7ff460 rip = 0x00007ffd9307133f 17:42:28 INFO - Found by: call frame info 17:42:28 INFO - 7 xul.dll!XRE_main(int,char * * const,mozilla::BootstrapConfig const &) [nsAppRunner.cpp:5b0de4548020 : 4960 + 0xd] 17:42:28 INFO - rbx = 0x000000000000012e rbp = 0x00007ffd95323260 17:42:28 INFO - rsp = 0x0000004a1e7ff3f0 r12 = 0x0000004a1e7ff488 17:42:28 INFO - r13 = 0x0000000080000000 r14 = 0x00000207acdbc148 17:42:28 INFO - r15 = 0x0000004a1e7ff460 rip = 0x00007ffd931c5c73 17:42:28 INFO - Found by: call frame info 17:42:28 INFO - 8 firefox.exe!NS_internal_main(int,char * *,char * *) [nsBrowserApp.cpp:5b0de4548020 : 309 + 0x23e] 17:42:28 INFO - rbx = 0x000000000000012e rbp = 0x00007ffd95323260 17:42:28 INFO - rsp = 0x0000004a1e7ff5e0 r12 = 0x0000004a1e7ff488 17:42:28 INFO - r13 = 0x0000000080000000 r14 = 0x00000207acdbc148 17:42:28 INFO - r15 = 0x0000004a1e7ff460 rip = 0x00007ff6a0541a52 17:42:28 INFO - Found by: call frame info 17:42:28 INFO - 9 firefox.exe!wmain [nsWindowsWMain.cpp:5b0de4548020 : 115 + 0x14] 17:42:28 INFO - rbx = 0x000000000000012e rbp = 0x00007ffd95323260 17:42:28 INFO - rsp = 0x0000004a1e7ff9e0 r12 = 0x0000004a1e7ff488 17:42:28 INFO - r13 = 0x0000000080000000 r14 = 0x00000207acdbc148 17:42:28 INFO - r15 = 0x0000004a1e7ff460 rip = 0x00007ff6a05411d0 17:42:28 INFO - Found by: call frame info 17:42:28 INFO - 10 firefox.exe!__scrt_common_main_seh [exe_common.inl : 253 + 0x22] 17:42:28 INFO - rbx = 0x000000000000012e rbp = 0x00007ffd95323260 17:42:28 INFO - rsp = 0x0000004a1e7ffa30 r12 = 0x0000004a1e7ff488 17:42:28 INFO - r13 = 0x0000000080000000 r14 = 0x00000207acdbc148 17:42:28 INFO - r15 = 0x0000004a1e7ff460 rip = 0x00007ff6a0546eb5 17:42:28 INFO - Found by: call frame info 17:42:28 INFO - 11 kernel32.dll!BaseThreadInitThunk + 0x14 17:42:28 INFO - rbx = 0x000000000000012e rbp = 0x00007ffd95323260 17:42:28 INFO - rsp = 0x0000004a1e7ffa70 r12 = 0x0000004a1e7ff488 17:42:28 INFO - r13 = 0x0000000080000000 r14 = 0x00000207acdbc148 17:42:28 INFO - r15 = 0x0000004a1e7ff460 rip = 0x00007ffdc2362774 17:42:28 INFO - Found by: call frame info 17:42:28 INFO - 12 ntdll.dll!SdbpCheckMatchingRegistryEntry + 0x29d 17:42:28 INFO - rbx = 0x000000000000012e rbp = 0x00007ffd95323260 17:42:28 INFO - rsp = 0x0000004a1e7ffaa0 r12 = 0x0000004a1e7ff488 17:42:28 INFO - r13 = 0x0000000080000000 r14 = 0x00000207acdbc148 17:42:28 INFO - r15 = 0x0000004a1e7ff460 rip = 0x00007ffdc2470d61 17:42:28 INFO - Found by: call frame info
Component: DOM → Audio/Video
https://treeherder.mozilla.org/logviewer.html#?job_id=132137864&repo=try&lineNumber=3297 It crashed at HTMLMediaElement.cpp:3777 https://hg.mozilla.org/try/file/d7aa60020a02/dom/html/HTMLMediaElement.cpp#l3777 It shows Observe() is called after Unsubscribe() which calls nsContentUtils::UnregisterShutdownObserver(this) and set mPhase to Phase::Unsubscribed. Hi smaug, Is it possible for Observe() to be called after nsContentUtils::UnregisterShutdownObserver(this)? I expect UnregisterShutdownObserver() will prevent future notifications to come.
Flags: needinfo?(bugs)
If UnregisterShutdownObserver is called while some other observer is being handled, then Observe may be called, at least based on http://searchfox.org/mozilla-central/rev/d08b24e613cac8c9c5a4131452459241010701e0/xpcom/ds/nsObserverList.cpp#108-109,111-112
Flags: needinfo?(bugs)
Attachment #8910187 - Flags: review?(kaku)
Attachment #8910188 - Flags: review?(kaku)
Comment on attachment 8910187 [details] Bug 1401366. P1 - format HTMLMediaElement::ShutdownObserver. https://reviewboard.mozilla.org/r/181684/#review187044
Attachment #8910187 - Flags: review?(kaku) → review+
Comment on attachment 8910188 [details] Bug 1401366. P2 - bail out Observe() if not subcribed per comment 2. https://reviewboard.mozilla.org/r/181686/#review187046 r+ assuming that https://bugzilla.mozilla.org/show_bug.cgi?id=1401366#c2 is right. But why? Is it bacause that "removing observer" and "handling observer" are async operations?
Attachment #8910188 - Flags: review?(kaku) → review+
No. They are not async as far as I can tell. I guess this is because some other observer causes ~HTMLMediaElement() to run (either by spinning the event loop or dropping the last reference to it) which will call ShutdownObserver::Unsubscribe().
Assignee: nobody → jwwang
Component: Audio/Video → Audio/Video: Playback
Pushed by jwwang@mozilla.com: https://hg.mozilla.org/integration/autoland/rev/0848279b2b72 P1 - format HTMLMediaElement::ShutdownObserver. r=kaku https://hg.mozilla.org/integration/autoland/rev/f9e527aa4ba5 P2 - bail out Observe() if not subcribed per comment 2. r=kaku
Status: NEW → RESOLVED
Closed: 8 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla57
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Created:
Updated:
Size: