Bug 1401366

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

RESOLVED FIXED in Firefox 57

Get help with this page

Status

()

Product:

Component:

Type:

defect

Importance:

critical

Status:

RESOLVED FIXED

Opened:

2 years ago

Updated:

8 months ago

People

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

Tracking

({crash, intermittent-failure})

Version:

unspecified

Target:

mozilla57

Keywords:

crash, intermittent-failure

Points:

---

Firefox Tracking Flags

(firefox-esr52 unaffected, firefox55 unaffected, firefox56 unaffected, firefox57 fixed)

Tracking Flags:

Tracking

Status

firefox-esr52

---

unaffected

firefox55

---

unaffected

firefox56

---

unaffected

firefox57

---

fixed

Details

(crash signature)

Attachments

(2 attachments)

Bug 1401366. P1 - format HTMLMediaElement::ShutdownObserver. 2 years ago JW Wang [:jwwang] [:jw_wang] 59 bytes, text/x-review-board-request	kaku : review+	Details
Bug 1401366. P2 - bail out Observe() if not subcribed per comment 2. 2 years ago JW Wang [:jwwang] [:jw_wang] 59 bytes, text/x-review-board-request	kaku : review+	Details

Treeherder Bug Filer

Reporter

Description

•

2 years ago

treeherder

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

Olli Pettay [:smaug]

Updated

•

2 years ago

Component: DOM → Audio/Video

JW Wang [:jwwang] [:jw_wang]

Assignee

Comment 1

•

2 years ago

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)

Olli Pettay [:smaug]

Comment 2

•

2 years ago

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)

Comment hidden (mozreview-request)

Review commit: https://reviewboard.mozilla.org/r/181684/diff/#index_header
See other reviews: https://reviewboard.mozilla.org/r/181684/

Comment hidden (mozreview-request)

Review commit: https://reviewboard.mozilla.org/r/181686/diff/#index_header
See other reviews: https://reviewboard.mozilla.org/r/181686/

JW Wang [:jwwang] [:jw_wang]

Assignee

Updated

•

2 years ago

Attachment #8910187 - Flags: review?(kaku)

Attachment #8910188 - Flags: review?(kaku)

Tzuhao Kuo [:kaku]

Comment 5

•

2 years ago

mozreview-review

Comment on attachment 8910187 [details]
Bug 1401366. P1 - format HTMLMediaElement::ShutdownObserver.

https://reviewboard.mozilla.org/r/181684/#review187044

Attachment #8910187 - Flags: review?(kaku) → review+

Tzuhao Kuo [:kaku]

Comment 6

•

2 years ago

mozreview-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+

JW Wang [:jwwang] [:jw_wang]

Assignee

Comment 7

•

2 years ago

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().

JW Wang [:jwwang] [:jw_wang]

Assignee

Updated

•

2 years ago

Assignee: nobody → jwwang

Component: Audio/Video → Audio/Video: Playback

Pulsebot

Comment 8

•

2 years ago

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

Wes Kocher (:KWierso)

Comment 9

•

2 years ago

bugherder

https://hg.mozilla.org/mozilla-central/rev/0848279b2b72
https://hg.mozilla.org/mozilla-central/rev/f9e527aa4ba5

Status: NEW → RESOLVED

Closed: 2 years ago

status-firefox57: --- → fixed

Resolution: --- → FIXED

Target Milestone: --- → mozilla57

Ryan VanderMeulen [:RyanVM]

Updated

•

2 years ago

status-firefox55: --- → unaffected

status-firefox56: --- → unaffected

status-firefox-esr52: --- → unaffected

Comment hidden (Intermittent Failures Robot)

18 failures in 943 pushes (0.019 failures/push) were associated with this bug in the last 7 days.    

Repository breakdown:
* autoland: 11
* mozilla-inbound: 7

Platform breakdown:
* windows7-32: 6
* windows7-32-stylo-disabled: 5
* windows10-64: 4
* windows10-64-stylo-disabled: 3

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1401366&startday=2017-09-18&endday=2017-09-24&tree=all

Karl Tomlinson (:karlt)

Updated

•

8 months ago

Bugzilla

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

Status

()

People

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

Tracking

({crash, intermittent-failure})

Firefox Tracking Flags

(firefox-esr52 unaffected, firefox55 unaffected, firefox56 unaffected, firefox57 fixed)

Details

(crash signature)

Security

(public)

User Story

Attachments

(2 attachments)

Description

Updated

Comment 1

Comment 2

Comment 3

Comment 4

Updated

Comment 5

Comment 6

Comment 7

Updated

Comment 8

Comment 9

Updated

Comment 10

Updated

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

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