Closed Bug 1508626 Opened 2 years ago Closed 1 month ago

Intermittent toolkit/components/extensions/test/xpcshell/test_ext_storage_telemetry.js | application crashed [@ mozalloc_abort]

Categories

(Core :: Graphics: Text, defect, P3)

defect

Tracking

()

RESOLVED FIXED
mozilla77
Tracking Status
firefox-esr68 --- wontfix
firefox68 --- wontfix
firefox75 --- wontfix
firefox76 --- wontfix
firefox77 --- fixed

People

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

References

Details

(Keywords: crash, intermittent-failure)

Crash Data

Attachments

(1 file)

Filed by: ncsoregi [at] mozilla.com

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

https://queue.taskcluster.net/v1/task/dyozgT-9Qo6CxgIxD24qpg/runs/0/artifacts/public/logs/live_backing.log

03:10:20     INFO -  TEST-START | toolkit/components/places/tests/legacy/test_bookmarks.js
03:10:20     INFO -  TEST-PASS | toolkit/components/places/tests/history/test_insertMany.js | took 5870ms
03:10:20     INFO -  TEST-START | toolkit/components/places/tests/legacy/test_bookmarks_setNullTitle.js
03:10:21     INFO -  mozcrash Saved minidump as /Users/cltbld/tasks/task_1542710567/build/blobber_upload_dir/F28ECFA5-4CFE-42AE-AFB8-9393E198A172.dmp
03:10:21     INFO -  mozcrash Saved app info as /Users/cltbld/tasks/task_1542710567/build/blobber_upload_dir/F28ECFA5-4CFE-42AE-AFB8-9393E198A172.extra
03:10:21  WARNING -  PROCESS-CRASH | xpcshell-remote.ini:toolkit/components/extensions/test/xpcshell/test_ext_storage_telemetry.js | application crashed [@ mozalloc_abort]
03:10:21     INFO -  Crash dump filename: /var/folders/wy/y3t0hbzn5l9120j9pyl28bp400000w/T/xpc-other-7f4NGC/F28ECFA5-4CFE-42AE-AFB8-9393E198A172.dmp
03:10:21     INFO -  Operating system: Mac OS X
03:10:21     INFO -                    10.10.5 14F27
03:10:21     INFO -  CPU: amd64
03:10:21     INFO -       family 6 model 69 stepping 1
03:10:21     INFO -       4 CPUs
03:10:21     INFO -  GPU: UNKNOWN
03:10:21     INFO -  Crash reason:  EXC_BAD_ACCESS / KERN_INVALID_ADDRESS
03:10:21     INFO -  Crash address: 0x0
03:10:21     INFO -  Process uptime: 32 seconds
03:10:21     INFO -  Thread 0 (crashed)
03:10:21     INFO -   0  libmozglue.dylib!mozalloc_abort [mozalloc_abort.cpp:8e08c23784f5f58d1f24bf1f783ad8b827ce688c : 35 + 0x0]
03:10:21     INFO -      rax = 0x0000000113e5ec92   rdx = 0x00007fff75da31f8
03:10:21     INFO -      rcx = 0x0000000113e626b0   rbx = 0x00007fff75da3c50
03:10:21     INFO -      rsi = 0x00002c0000002c00   rdi = 0x00002b0000002c03
03:10:21     INFO -      rbp = 0x00007fff54f42100   rsp = 0x00007fff54f420f0
03:10:21     INFO -       r8 = 0x00007fff54f420a0    r9 = 0x00007fff76989300
03:10:21     INFO -      r10 = 0x0000000000000000   r11 = 0x0000000000000246
03:10:21     INFO -      r12 = 0x00007fff54f42368   r13 = 0x0000000000000085
03:10:21     INFO -      r14 = 0x00007fff54f42160   r15 = 0x00007fff54f43e69
03:10:21     INFO -      rip = 0x0000000113e4270a
03:10:21     INFO -      Found by: given as instruction pointer in context
03:10:21     INFO -   1  XUL!Abort(char const*) [nsDebugImpl.cpp:8e08c23784f5f58d1f24bf1f783ad8b827ce688c : 471 + 0x5]
03:10:21     INFO -      rbp = 0x00007fff54f42110   rsp = 0x00007fff54f42110
03:10:21     INFO -      rip = 0x000000010afdcdd9
03:10:21     INFO -      Found by: previous frame's frame pointer
03:10:21     INFO -   2  XUL!NS_DebugBreak [nsDebugImpl.cpp:8e08c23784f5f58d1f24bf1f783ad8b827ce688c : 458 + 0x8]
03:10:21     INFO -      rbp = 0x00007fff54f42590   rsp = 0x00007fff54f42120
03:10:21     INFO -      rip = 0x000000010afdcb56
03:10:21     INFO -      Found by: previous frame's frame pointer
03:10:21     INFO -   3  XUL!mozilla::ThreadEventTarget::Dispatch(already_AddRefed<nsIRunnable>, unsigned int) [ThreadEventTarget.cpp:8e08c23784f5f58d1f24bf1f783ad8b827ce688c : 133 + 0x25]
03:10:21     INFO -      rbp = 0x00007fff54f425f0   rsp = 0x00007fff54f425a0
03:10:21     INFO -      rip = 0x000000010b0b8431
03:10:21     INFO -      Found by: previous frame's frame pointer
03:10:21     INFO -   4  XUL!nsThread::Dispatch(already_AddRefed<nsIRunnable>, unsigned int) [nsThread.cpp:8e08c23784f5f58d1f24bf1f783ad8b827ce688c : 770 + 0x8]
03:10:21     INFO -      rbp = 0x00007fff54f42620   rsp = 0x00007fff54f42600
03:10:21     INFO -      rip = 0x000000010b0c1c18
03:10:21     INFO -      Found by: previous frame's frame pointer
03:10:21     INFO -   5  XUL!gfxFontInfoLoader::StartLoader(unsigned int, unsigned int) [gfxFontInfoLoader.cpp:8e08c23784f5f58d1f24bf1f783ad8b827ce688c : 196 + 0x8]
03:10:21     INFO -      rbp = 0x00007fff54f42670   rsp = 0x00007fff54f42630
03:10:21     INFO -      rip = 0x000000010c34d291
03:10:21     INFO -      Found by: previous frame's frame pointer
03:10:21     INFO -   6  XUL!nsTimerImpl::Fire(int) [nsTimerImpl.cpp:8e08c23784f5f58d1f24bf1f783ad8b827ce688c : 684 + 0x8]
03:10:21     INFO -      rbp = 0x00007fff54f42720   rsp = 0x00007fff54f42680
03:10:21     INFO -      rip = 0x000000010b0d76d1
03:10:21     INFO -      Found by: previous frame's frame pointer
03:10:21     INFO -   7  XUL!nsTimerEvent::Run() [TimerThread.cpp:8e08c23784f5f58d1f24bf1f783ad8b827ce688c : 297 + 0x5]
03:10:21     INFO -      rbp = 0x00007fff54f42750   rsp = 0x00007fff54f42730
03:10:21     INFO -      rip = 0x000000010b0ba4aa
03:10:21     INFO -      Found by: previous frame's frame pointer
03:10:21     INFO -   8  XUL!nsThread::ProcessNextEvent(bool, bool*) [nsThread.cpp:8e08c23784f5f58d1f24bf1f783ad8b827ce688c : 1244 + 0x6]
03:10:21     INFO -      rbp = 0x00007fff54f42cb0   rsp = 0x00007fff54f42760
03:10:21     INFO -      rip = 0x000000010b0c388c
03:10:21     INFO -      Found by: previous frame's frame pointer
03:10:21     INFO -   9  XUL!NS_ProcessPendingEvents(nsIThread*, unsigned int) [nsThreadUtils.cpp:8e08c23784f5f58d1f24bf1f783ad8b827ce688c : 472 + 0xf]
03:10:21     INFO -      rbp = 0x00007fff54f42cf0   rsp = 0x00007fff54f42cc0
03:10:21     INFO -      rip = 0x000000010b0c0d41
03:10:21     INFO -      Found by: previous frame's frame pointer
03:10:21     INFO -  10  XUL!mozilla::ShutdownXPCOM(nsIServiceManager*) [XPCOMInit.cpp:8e08c23784f5f58d1f24bf1f783ad8b827ce688c : 916 + 0xa]
03:10:21     INFO -      rbp = 0x00007fff54f42d60   rsp = 0x00007fff54f42d00
03:10:21     INFO -      rip = 0x000000010b0fc437
03:10:21     INFO -      Found by: previous frame's frame pointer
03:10:21     INFO -  11  XUL!XRE_TermEmbedding() [nsEmbedFunctions.cpp:8e08c23784f5f58d1f24bf1f783ad8b827ce688c : 228 + 0x7]
03:10:21     INFO -      rbp = 0x00007fff54f42d80   rsp = 0x00007fff54f42d70
03:10:21     INFO -      rip = 0x0000000110153028
03:10:21     INFO -      Found by: previous frame's frame pointer
03:10:21     INFO -  12  XUL!mozilla::ipc::ScopedXREEmbed::Stop() [ScopedXREEmbed.cpp:8e08c23784f5f58d1f24bf1f783ad8b827ce688c : 108 + 0x5]
03:10:21     INFO -      rbp = 0x00007fff54f42da0   rsp = 0x00007fff54f42d90
03:10:21     INFO -      rip = 0x000000010b7798e3
03:10:21     INFO -      Found by: previous frame's frame pointer
03:10:21     INFO -  13  XUL!XRE_InitChildProcess(int, char**, XREChildData const*) [nsEmbedFunctions.cpp:8e08c23784f5f58d1f24bf1f783ad8b827ce688c : 791 + 0x9]
03:10:21     INFO -      rbp = 0x00007fff54f43090   rsp = 0x00007fff54f42db0
03:10:21     INFO -      rip = 0x0000000110153d84
03:10:21     INFO -      Found by: previous frame's frame pointer
03:10:21     INFO -  14  plugin-container!main [plugin-container.cpp:8e08c23784f5f58d1f24bf1f783ad8b827ce688c : 50 + 0x13]
03:10:21     INFO -      rbp = 0x00007fff54f430d0   rsp = 0x00007fff54f430a0
03:10:21     INFO -      rip = 0x000000010acbcf39
03:10:21     INFO -      Found by: previous frame's frame pointer
03:10:21     INFO -  15  libdyld.dylib + 0x35c9
03:10:21     INFO -      rbp = 0x00007fff54f430e8   rsp = 0x00007fff54f430e0
03:10:21     INFO -      rip = 0x00007fff8e9995c9
03:10:21     INFO -      Found by: previous frame's frame pointer
03:10:21     INFO -  16  libdyld.dylib + 0x35c9
03:10:21     INFO -      rbp = 0x00007fff54f430e8   rsp = 0x00007fff54f430e8
03:10:21     INFO -      rip = 0x00007fff8e9995c9
03:10:21     INFO -      Found by: stack scanning
This is a failed assertion (in a debug build):

https://treeherder.mozilla.org/logviewer.html#?job_id=212846577&repo=mozilla-inbound&lineNumber=8808-8820

03:19:09     INFO -  PID 4798 | #01: nsThread::Dispatch(already_AddRefed<nsIRunnable>, unsigned int) [mfbt/AlreadyAddRefed.h:126]
03:19:09     INFO -  PID 4798 | #02: gfxFontInfoLoader::StartLoader(unsigned int, unsigned int) [mfbt/AlreadyAddRefed.h:126]
03:19:09     INFO -  PID 4798 | #03: nsTimerImpl::Fire(int) [xpcom/threads/nsTimerImpl.cpp:684]
03:19:09     INFO -  PID 4798 | #04: nsTimerEvent::Run() [xpcom/threads/TimerThread.cpp:299]
03:19:09     INFO -  PID 4798 | #05: nsThread::ProcessNextEvent(bool, bool*) [xpcom/threads/nsThread.cpp:1231]
03:19:09     INFO -  PID 4798 | #06: NS_ProcessPendingEvents(nsIThread*, unsigned int) [xpcom/threads/nsThreadUtils.cpp:472]
03:19:09     INFO -  PID 4798 | #07: mozilla::ShutdownXPCOM(nsIServiceManager*) [xpcom/build/XPCOMInit.cpp:920]
03:19:09     INFO -  PID 4798 | #08: XRE_TermEmbedding() [toolkit/xre/nsEmbedFunctions.cpp:229]
03:19:09     INFO -  PID 4798 | #09: mozilla::ipc::ScopedXREEmbed::Stop() [ipc/glue/ScopedXREEmbed.cpp:109]
03:19:09     INFO -  PID 4798 | #10: XRE_InitChildProcess(int, char**, XREChildData const*) [toolkit/xre/nsEmbedFunctions.cpp:792]
03:19:09     INFO -  PID 4798 | #11: main [ipc/contentproc/plugin-container.cpp:50]
03:19:09     INFO -  PID 4798 | [Child 4824, Main Thread] ###!!! ASSERTION: Failed Dispatch after xpcom-shutdown-threads: 'false', file /builds/worker/workspace/build/src/xpcom/threads/ThreadEventTarget.cpp, line 133
03:19:09     INFO -  PID 4798 | Hit MOZ_CRASH() at /builds/worker/workspace/build/src/memory/mozalloc/mozalloc_abort.cpp:35

Taking a guess at a more appropriate comment based on the stack...
Component: General → Graphics: Text
Product: WebExtensions → Core
Status: NEW → RESOLVED
Closed: 1 year ago
Resolution: --- → INCOMPLETE
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---

Moving these bugs (intermittent test failures with crashes) out of P5.

Priority: P5 → --

Jonathan, seems like gfxFontInfoLoader.cpp is created a timer after shutdown off the main thread. Is the simple fix here to just not create the timer in that scenario?

Flags: needinfo?(jfkthame)
Priority: -- → P3

Yeah, looks like the gfxFontInfoLoader timer (which would have been created during platform font-list init, but with an initial delay) has fired just after shutdown started.

IIRC the loader is supposed to have an observer for shutdown notifications, and cancel itself, but there may be a race whereby the cancellation doesn't always happen soon enough, or something. We surely don't need it to be doing any more work once we're shutting down the browser.

Flags: needinfo?(jfkthame)
Pushed by lsalzman@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/c8fc7c4dc43c
add assertions to diagnose why the font loader is running after shutdown. r=jfkthame
Status: REOPENED → RESOLVED
Closed: 1 year ago1 year ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla68

Leaving the bug open till we get in some assert information from the patch to determine the exact cause and find a real fix...

Status: RESOLVED → REOPENED
Resolution: FIXED → ---
See Also: → 1622826

Marking this as closed since as of bug 1622826 we have a reasonably good understanding of the cause being a failure of the shutdown observer in gfxFontInfoLoader to be triggered under some circumstances while font info is still loading (thus the race) and that we just needed to observe some more shutdown events to ensure things properly get canceled.

Status: REOPENED → RESOLVED
Closed: 1 year ago1 month ago
Resolution: --- → FIXED
Assignee: nobody → lsalzman
Target Milestone: mozilla68 → mozilla77
You need to log in before you can comment on or make changes to this bug.