Intermittent e10s PROCESS-CRASH | Main app process exited normally | application crashed [@ mozilla::image::VectorImage::GetWidth(int*)] after Assertion failure: rootElem (Should have a root SVG elem, since we finished loading without errors), at /build

RESOLVED FIXED in Firefox 51

Status

()

defect
P3
normal
RESOLVED FIXED
3 years ago
2 years ago

People

(Reporter: philor, Assigned: aosmond)

Tracking

(Blocks 1 bug, {assertion, intermittent-failure})

unspecified
mozilla52
Points:
---
Dependency tree / graph

Firefox Tracking Flags

(e10s+, firefox50 wontfix, firefox51 fixed, firefox52 fixed)

Details

(Whiteboard: [gfx-noted])

Attachments

(2 attachments, 2 obsolete attachments)

Updated

3 years ago
tracking-e10s: --- → ?
Component: Graphics → ImageLib
Whiteboard: [gfx-noted]
Comment hidden (Intermittent Failures Robot)
Intermittent test crash
Priority: -- → P3
Comment hidden (Intermittent Failures Robot)
Assignee

Comment 4

3 years ago
Crashes while trying to generate a memory report during shutdown:
- imgMemoryReporter registers itself as a memory reporter at startup and never unregisters itself.
- VectorImages are accessed when generating a memory report and require the SVG data stored in SVGDocumentWrapper to be present to get metadata (like width). It doesn't expect that data to get freed once it has finished loading successfully.
- SVGDocumentWrapper listens for the xpcom-shutdown event and releases its image data when that occurs.
- In the cases where the assert trips, a JS component appears have had a request to generate memory report in the event queue somewhere, and that event is triggered while xpcom-shutdown is being broadcasted (hence it is racy / intermittent).

Assuming the memory report is really queued up and shutdown interrupted it before it could get processed, then we need to change imgMemoryReporter to deregister itself as a memory reporter before xpcom-shutdown gets broadcasted (or we can guarantee we run before the memory report generation...).
Assignee: nobody → aosmond
Status: NEW → ASSIGNED
Assignee

Updated

3 years ago
Duplicate of this bug: 1266042
Assignee

Comment 8

3 years ago
A more recent reproduction which demonstrates the nsSocketTransportService connection:

https://treeherder.mozilla.org/logviewer.html#?repo=mozilla-inbound&job_id=35303593#L5911

07:37:25     INFO -  Crash reason:  SIGSEGV
07:37:25     INFO -  Crash address: 0x0
07:37:25     INFO -  Thread 0 (crashed)
07:37:25     INFO -   0  libxul.so!mozilla::image::VectorImage::GetWidth [VectorImage.cpp:79e57fc02263 : 509 + 0x0]
07:37:25     INFO -      rbx = 0x00007ffec13d4320   r12 = 0x00007feb0f846b80
07:37:25     INFO -      r13 = 0x00007ffec13d43d0   r14 = 0x0000000000409413
07:37:25     INFO -      r15 = 0x0000000000000001   rip = 0x00007feb33f601d9
07:37:25     INFO -      rsp = 0x00007ffec13d4300   rbp = 0x00007ffec13d4310
07:37:25     INFO -      Found by: given as instruction pointer in context
07:37:25     INFO -   1  libxul.so!mozilla::image::ImageMemoryCounter::ImageMemoryCounter [Image.cpp:79e57fc02263 : 32 + 0x2]
07:37:25     INFO -      rbx = 0x00007ffec13d43c0   r12 = 0x00007feb0f846b80
07:37:25     INFO -      r13 = 0x00007ffec13d43d0   r14 = 0x0000000000409413
07:37:25     INFO -      r15 = 0x0000000000000001   rip = 0x00007feb33f553ec
07:37:25     INFO -      rsp = 0x00007ffec13d4320   rbp = 0x00007ffec13d4360
07:37:25     INFO -      Found by: call frame info
07:37:25     INFO -   2  libxul.so!imgMemoryReporter::ImagesContentUsedUncompressedDistinguishedAmount [imgLoader.cpp:79e57fc02263 : 138 + 0x13]
07:37:25     INFO -      rbx = 0x00007ffec13d43c0   r12 = 0x0000000000000000
07:37:25     INFO -      r13 = 0x0000000000000000   r14 = 0x00007ffec13d4390
07:37:25     INFO -      r15 = 0x00007ffec13d4380   rip = 0x00007feb33f405ad
07:37:25     INFO -      rsp = 0x00007ffec13d4370   rbp = 0x00007ffec13d4430
07:37:25     INFO -      Found by: call frame info
07:37:25     INFO -   3  libxul.so!GetInfallibleAmount [nsMemoryReporterManager.cpp:79e57fc02263 : 2373 + 0x1]
07:37:25     INFO -      rbx = 0x00007ffec13d45b8   r12 = 0x00007feb3684e800
07:37:25     INFO -      r13 = 0x0000000000000000   r14 = 0x00007ffec13d4501
07:37:25     INFO -      r15 = 0x00007ffec13d451c   rip = 0x00007feb3348e19d
07:37:25     INFO -      rsp = 0x00007ffec13d4440   rbp = 0x00007ffec13d4450
07:37:25     INFO -      Found by: call frame info
07:37:25     INFO -   4  libxul.so!NS_InvokeByIndex [xptcinvoke_x86_64_unix.cpp:79e57fc02263 : 182 + 0x40]
07:37:25     INFO -      rbx = 0x0000000000000001   r12 = 0x00007feb3684e800
07:37:25     INFO -      r13 = 0x0000000000000000   r14 = 0x00007ffec13d4501
07:37:25     INFO -      r15 = 0x00007ffec13d451c   rip = 0x00007feb334ee6cf
07:37:25     INFO -      rsp = 0x00007ffec13d4460   rbp = 0x00007ffec13d4500
07:37:25     INFO -      Found by: call frame info

...

07:37:25     INFO -  82  libxul.so!nsTimerImpl::Fire [nsTimerImpl.cpp:79e57fc02263 : 524 + 0xc]
07:37:25     INFO -      rip = 0x00007feb334eb029   rsp = 0x00007ffec13da660
07:37:25     INFO -      rbp = 0x00007ffec13da6d0
07:37:25     INFO -      Found by: stack scanning
07:37:25     INFO -  83  libxul.so!nsTimerEvent::Run [TimerThread.cpp:79e57fc02263 : 286 + 0xf]
07:37:25     INFO -      rbx = 0x00007feb12c33138   r12 = 0x00007feb12c33160
07:37:25     INFO -      r13 = 0x00007ffec13da740   r14 = 0x00007ffec13da738
07:37:25     INFO -      r15 = 0x00007ffec13da7cf   rip = 0x00007feb334e9211
07:37:25     INFO -      rsp = 0x00007ffec13da6e0   rbp = 0x00007ffec13da710
07:37:25     INFO -      Found by: call frame info
07:37:25     INFO -  84  libxul.so!nsThread::ProcessNextEvent [nsThread.cpp:79e57fc02263 : 1058 + 0x10]
07:37:25     INFO -      rbx = 0x00007feb24211500   r12 = 0x00007ffec13da748
07:37:25     INFO -      r13 = 0x00007ffec13da740   r14 = 0x00007ffec13da738
07:37:25     INFO -      r15 = 0x00007ffec13da7cf   rip = 0x00007feb334e4a2c
07:37:25     INFO -      rsp = 0x00007ffec13da720   rbp = 0x00007ffec13da7b0
07:37:25     INFO -      Found by: call frame info
07:37:25     INFO -  85  libxul.so!NS_ProcessNextEvent [nsThreadUtils.cpp:79e57fc02263 : 290 + 0xc]
07:37:25     INFO -      rbx = 0x0000000000000001   r12 = 0x00007feb0f90e5c0
07:37:26     INFO -      r13 = 0x00007ffec13da820   r14 = 0x00007feb24211738
07:37:26     INFO -      r15 = 0x00007feb24211748   rip = 0x00007feb3350ae6c
07:37:26     INFO -      rsp = 0x00007ffec13da7c0   rbp = 0x00007ffec13da7e0
07:37:26     INFO -      Found by: call frame info
07:37:26     INFO -  86  libxul.so!nsThread::Shutdown [nsThread.cpp:79e57fc02263 : 917 + 0xe]
07:37:26     INFO -      rbx = 0x00007feb24211800   r12 = 0x00007feb0f90e5c0
07:37:26     INFO -      r13 = 0x00007ffec13da820   r14 = 0x00007feb24211738
07:37:26     INFO -      r15 = 0x00007feb24211748   rip = 0x00007feb334e6404
07:37:26     INFO -      rsp = 0x00007ffec13da7f0   rbp = 0x00007ffec13da800
07:37:26     INFO -      Found by: call frame info
07:37:26     INFO -  87  libxul.so!mozilla::net::nsSocketTransportService::Shutdown [nsSocketTransportService2.cpp:79e57fc02263 : 583 + 0x10]
07:37:26     INFO -      rbx = 0x00007feb24211700   r12 = 0x00007ffec13da818
07:37:26     INFO -      r13 = 0x00007ffec13da820   r14 = 0x00007feb24211738
07:37:26     INFO -      r15 = 0x00007feb24211748   rip = 0x00007feb335a6289
07:37:26     INFO -      rsp = 0x00007ffec13da810   rbp = 0x00007ffec13da860
07:37:26     INFO -      Found by: call frame info
07:37:26     INFO -  88  libxul.so!mozilla::net::nsIOService::SetOffline [nsIOService.cpp:79e57fc02263 : 1108 + 0x11]
07:37:26     INFO -      rbx = 0x00007feb24288780   r12 = 0x00007ffec13da878
07:37:26     INFO -      r13 = 0x00007ffec13da880   r14 = 0x00007feb242888b0
07:37:26     INFO -      r15 = 0x00007feb242887d8   rip = 0x00007feb33574af3
07:37:26     INFO -      rsp = 0x00007ffec13da870   rbp = 0x00007ffec13da8c0
07:37:26     INFO -      Found by: call frame info
07:37:26     INFO -  89  libxul.so!mozilla::net::nsIOService::Observe [nsIOService.cpp:79e57fc02263 : 1478 + 0xc]
07:37:26     INFO -      rbx = 0x00007feb24288780   r12 = 0x00007feb242887dc
07:37:26     INFO -      r13 = 0x0000000000000000   r14 = 0x00007feb36833bb7
07:37:26     INFO -      r15 = 0x00007feb2989ed58   rip = 0x00007feb33580549
07:37:26     INFO -      rsp = 0x00007ffec13da8d0   rbp = 0x00007ffec13da970
07:37:26     INFO -      Found by: call frame info
07:37:26     INFO -  90  libxul.so!nsObserverList::NotifyObservers [nsObserverList.cpp:79e57fc02263 : 112 + 0xe]
07:37:26     INFO -      rbx = 0x00007ffec13da988   r12 = 0x0000000000000032
07:37:26     INFO -      r13 = 0x00007feb2989ed58   r14 = 0x00007feb36833bb7
07:37:26     INFO -      r15 = 0x0000000000000000   rip = 0x00007feb334b034a
07:37:26     INFO -      rsp = 0x00007ffec13da980   rbp = 0x00007ffec13da9c0
07:37:26     INFO -      Found by: call frame info
07:37:26     INFO -  91  libxul.so!nsObserverService::NotifyObservers [nsObserverService.cpp:79e57fc02263 : 281 + 0x10]
07:37:26     INFO -      rbx = 0x00007feb36833bb7   r12 = 0x00007feb22427d68
07:37:26     INFO -      r13 = 0x00007feb2989ed58   r14 = 0x0000000000000000
07:37:26     INFO -      r15 = 0x0000000000000000   rip = 0x00007feb334b0477
07:37:26     INFO -      rsp = 0x00007ffec13da9d0   rbp = 0x00007ffec13da9f0
07:37:26     INFO -      Found by: call frame info
07:37:26     INFO -  92  libxul.so!mozilla::ShutdownXPCOM [XPCOMInit.cpp:79e57fc02263 : 887 + 0x19]
07:37:26     INFO -      rbx = 0x00007ffec13daa20   r12 = 0x00007ffec13daa48
07:37:26     INFO -      r13 = 0x00007ffec13daa18   r14 = 0x00007ffec13daa28
07:37:26     INFO -      r15 = 0x0000000000000000   rip = 0x00007feb33504dbd
07:37:26     INFO -      rsp = 0x00007ffec13daa00   rbp = 0x00007ffec13daa80
07:37:26     INFO -      Found by: call frame info
07:37:26     INFO -  93  libxul.so!XRE_TermEmbedding [nsEmbedFunctions.cpp:79e57fc02263 : 208 + 0x6]
07:37:26     INFO -      rbx = 0x00007feb298c4a98   r12 = 0x00007ffec13daaf0
07:37:26     INFO -      r13 = 0x00007ffec13dab08   r14 = 0x00007feb298c4000
07:37:26     INFO -      r15 = 0x0000000000000001   rip = 0x00007feb35969750
07:37:26     INFO -      rsp = 0x00007ffec13daa90   rbp = 0x00007ffec13daaa0
07:37:26     INFO -      Found by: call frame info
07:37:26     INFO -  94  libxul.so!mozilla::ipc::ScopedXREEmbed::Stop [ScopedXREEmbed.cpp:79e57fc02263 : 117 + 0x4]
07:37:26     INFO -      rbx = 0x00007feb298c4a98   r12 = 0x00007ffec13daaf0
07:37:26     INFO -      r13 = 0x00007ffec13dab08   r14 = 0x00007feb298c4000
07:37:26     INFO -      r15 = 0x0000000000000001   rip = 0x00007feb338779af
07:37:26     INFO -      rsp = 0x00007ffec13daab0   rbp = 0x00007ffec13daac0
07:37:26     INFO -      Found by: call frame info
07:37:26     INFO -  95  libxul.so!XRE_InitChildProcess [nsEmbedFunctions.cpp:79e57fc02263 : 678 + 0x10]
07:37:26     INFO -      rbx = 0x00007ffec13daba8   r12 = 0x00007ffec13daaf0
07:37:26     INFO -      r13 = 0x00007ffec13dab08   r14 = 0x00007feb298c4000
07:37:26     INFO -      r15 = 0x0000000000000001   rip = 0x00007feb3596a965
07:37:26     INFO -      rsp = 0x00007ffec13daad0   rbp = 0x00007ffec13dad70
07:37:26     INFO -      Found by: call frame info
07:37:26     INFO -  96  plugin-container!content_process_main [plugin-container.cpp:79e57fc02263 : 197 + 0xd]
07:37:26     INFO -      rbx = 0x00007feb298410d8   r12 = 0x00007ffec13dad80
07:37:26     INFO -      r13 = 0x0000000000000009   r14 = 0x00007ffec13daea8
07:37:26     INFO -      r15 = 0x0000000000000000   rip = 0x0000000000409377
07:37:26     INFO -      rsp = 0x00007ffec13dad80   rbp = 0x00007ffec13dadc0
07:37:26     INFO -      Found by: call frame info
07:37:26     INFO -  97  libc-2.15.so + 0x217ec
07:37:26     INFO -      rbx = 0x0000000000000000   r12 = 0x0000000000408cbc
07:37:26     INFO -      r13 = 0x00007ffec13daea0   r14 = 0x0000000000000000
07:37:26     INFO -      r15 = 0x0000000000000000   rip = 0x00007feb318f77ed
07:37:26     INFO -      rsp = 0x00007ffec13dadd0   rbp = 0x0000000000000000
07:37:26     INFO -      Found by: call frame info
07:37:26     INFO -  98  plugin-container!MOZ_ReportAssertionFailure [Assertions.h:79e57fc02263 : 165 + 0x4]
07:37:26     INFO -      rip = 0x0000000000408af8   rsp = 0x00007ffec13dadf0
07:37:26     INFO -      Found by: stack scanning

As one can see from the trace, the fact that we try to shutdown the socket thread in xpcom-shutdown instead of xpcom-shutdown-threads means we start processing the main event queue when we should not be. Moving that thread shutdown to the right event should fix the problem.
Assignee

Comment 9

3 years ago
Break up patch for ease of reviewers.
Attachment #8792580 - Attachment is obsolete: true
Attachment #8792594 - Flags: review?(n.nethercote)
Comment on attachment 8792594 [details] [diff] [review]
Part 1. Unregister from handling image memory reports when shutting down., v1

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

Thank you for the fix.
Attachment #8792594 - Flags: review?(n.nethercote) → review+
Attachment #8792596 - Flags: review?(dd.mozilla) → review+

Comment 12

3 years ago
Pushed by aosmond@gmail.com:
https://hg.mozilla.org/integration/mozilla-inbound/rev/738bab069e73
Part 1. Unregister from handling image memory reports when shutting down. r=njn
https://hg.mozilla.org/integration/mozilla-inbound/rev/f451982cae7c
Part 2. Move socket transport service thread shutdown to xpcom-shutdown-threads. r=dragana

Comment 13

3 years ago
bugherder
https://hg.mozilla.org/mozilla-central/rev/738bab069e73
https://hg.mozilla.org/mozilla-central/rev/f451982cae7c
Status: ASSIGNED → RESOLVED
Last Resolved: 3 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla52
Please request Aurora/Beta approval on this assuming the risk is low enough to warrant doing so.
Flags: needinfo?(aosmond)
Assignee

Comment 15

3 years ago
(In reply to Ryan VanderMeulen [:RyanVM] from comment #14)
> Please request Aurora/Beta approval on this assuming the risk is low enough
> to warrant doing so.

The risk is fairly low, but the crash report volume for release/beta is also low (perhaps a dozen across all builds in the last 6 months). I'll request aurora.
Flags: needinfo?(aosmond)
Assignee

Comment 16

3 years ago
Comment on attachment 8792594 [details] [diff] [review]
Part 1. Unregister from handling image memory reports when shutting down., v1

Approval Request Comment
[Feature/regressing bug #]: N/A
[User impact if declined]: May crash with a null pointer dereference during shutdown. While infrequent, we still see crash reports in the wild.
[Describe test coverage new/current, TreeHerder]: e10s debug mochitests have intermittent failures during shutdown. Otherwise changes affect the normal shutdown path are thus are well exercised.
[Risks and why]: Low risk, changes well contained.
[String/UUID change made/needed]: N/A
Attachment #8792594 - Flags: approval-mozilla-aurora?
Assignee

Comment 17

3 years ago
Comment on attachment 8792596 [details] [diff] [review]
Part 2. Move socket transport service thread shutdown to xpcom-shutdown-threads., v2

Approval Request Comment
[Feature/regressing bug #]: N/A
[User impact if declined]: May crash with a null pointer dereference during shutdown. While infrequent, we still see crash reports in the wild.
[Describe test coverage new/current, TreeHerder]: e10s debug mochitests have intermittent failures during shutdown. Otherwise changes affect the normal shutdown path are thus are well exercised.
[Risks and why]: Low risk, changes well contained.
[String/UUID change made/needed]: N/A
Attachment #8792596 - Flags: approval-mozilla-aurora?
Comment on attachment 8792594 [details] [diff] [review]
Part 1. Unregister from handling image memory reports when shutting down., v1

Fix a potential crash related to e10s. Take it in 51 aurora.
Attachment #8792594 - Flags: approval-mozilla-aurora? → approval-mozilla-aurora+
Attachment #8792596 - Flags: approval-mozilla-aurora? → approval-mozilla-aurora+
Comment hidden (Intermittent Failures Robot)
You need to log in before you can comment on or make changes to this bug.