Closed Bug 1407505 Opened 2 years ago Closed 2 years ago

Intermittent CCov PROCESS-CRASH | tps | application crashed [@ js::jit::ExecutableAllocator::~ExecutableAllocator]

Categories

(Core :: JavaScript Engine, defect, P5, critical)

defect

Tracking

()

RESOLVED FIXED
mozilla58
Tracking Status
firefox-esr52 --- unaffected
firefox56 --- unaffected
firefox57 --- unaffected
firefox58 --- fixed

People

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

References

Details

(Keywords: crash, intermittent-failure)

Crash Data

Attachments

(1 file)

Summary: Intermittent PROCESS-CRASH | tps | application crashed [@ js::jit::ExecutableAllocator::~ExecutableAllocator] → Intermittent CCov PROCESS-CRASH | tps | application crashed [@ js::jit::ExecutableAllocator::~ExecutableAllocator]
after bug 1402473 landed, we started seeing this crash.

here is a recent log:
https://public-artifacts.taskcluster.net/SjwzQx-8RdmegGqinUbT2w/0/public/logs/live_backing.log

and here is some of the stack:
task 2017-10-09T23:22:55.106Z] 23:22:55     INFO -  Thread 0 (crashed)
[task 2017-10-09T23:22:55.106Z] 23:22:55     INFO -   0  libxul.so!js::jit::ExecutableAllocator::~ExecutableAllocator [ExecutableAllocator.cpp:2ed5e7fbf39e : 131 + 0x28]
[task 2017-10-09T23:22:55.107Z] 23:22:55     INFO -      rax = 0x00007ffe23876710   rdx = 0x0000000000000000
[task 2017-10-09T23:22:55.107Z] 23:22:55     INFO -      rcx = 0x00007fb56a1a72ad   rbx = 0x000000000224f2a0
[task 2017-10-09T23:22:55.108Z] 23:22:55     INFO -      rsi = 0x00007fb56a476770   rdi = 0x00007fb56a475540
[task 2017-10-09T23:22:55.108Z] 23:22:55     INFO -      rbp = 0x00007ffe238766d0   rsp = 0x00007ffe23876680
[task 2017-10-09T23:22:55.109Z] 23:22:55     INFO -       r8 = 0x00007fb56a476770    r9 = 0x00007fb56b53e740
[task 2017-10-09T23:22:55.109Z] 23:22:55     INFO -      r10 = 0x0000000000000000   r11 = 0x0000000000000000
[task 2017-10-09T23:22:55.110Z] 23:22:55     INFO -      r12 = 0x00007ffe238766f0   r13 = 0x000000000224f2a0
[task 2017-10-09T23:22:55.111Z] 23:22:55     INFO -      r14 = 0x000000000218a470   r15 = 0x000000000218a300
[task 2017-10-09T23:22:55.112Z] 23:22:55     INFO -      rip = 0x00007fb5561dca00
[task 2017-10-09T23:22:55.113Z] 23:22:55     INFO -      Found by: given as instruction pointer in context
[task 2017-10-09T23:22:55.114Z] 23:22:55     INFO -   1  libxul.so!js::jit::JitRuntime::~JitRuntime [ProtectedData.h:2ed5e7fbf39e : 66 + 0x2c]
[task 2017-10-09T23:22:55.114Z] 23:22:55     INFO -      rbx = 0x000000000224f2a0   rbp = 0x00007ffe23876710
[task 2017-10-09T23:22:55.115Z] 23:22:55     INFO -      rsp = 0x00007ffe238766e0   r12 = 0x00007ffe238766f0
[task 2017-10-09T23:22:55.116Z] 23:22:55     INFO -      r13 = 0x000000000224f2a0   r14 = 0x000000000218a470
[task 2017-10-09T23:22:55.117Z] 23:22:55     INFO -      r15 = 0x000000000218a300   rip = 0x00007fb555545ee8
[task 2017-10-09T23:22:55.118Z] 23:22:55     INFO -      Found by: call frame info
[task 2017-10-09T23:22:55.119Z] 23:22:55     INFO -   2  libxul.so!JSRuntime::destroyRuntime [Utility.h:2ed5e7fbf39e : 511 + 0x10]
[task 2017-10-09T23:22:55.120Z] 23:22:55     INFO -      rbx = 0x00000000020ac6c0   rbp = 0x00007ffe23876770
[task 2017-10-09T23:22:55.121Z] 23:22:55     INFO -      rsp = 0x00007ffe23876720   r12 = 0x00007ffe23876730
[task 2017-10-09T23:22:55.122Z] 23:22:55     INFO -      r13 = 0x000000000224f2a0   r14 = 0x000000000218a470
[task 2017-10-09T23:22:55.123Z] 23:22:55     INFO -      r15 = 0x000000000218a300   rip = 0x00007fb555cf3a6e
[task 2017-10-09T23:22:55.123Z] 23:22:55     INFO -      Found by: call frame info
[task 2017-10-09T23:22:55.124Z] 23:22:55     INFO -   3  libxul.so!js::DestroyContext [jscntxt.cpp:2ed5e7fbf39e : 249 + 0xc]
[task 2017-10-09T23:22:55.125Z] 23:22:55     INFO -      rbx = 0x00000000021927d0   rbp = 0x00007ffe23876810
[task 2017-10-09T23:22:55.126Z] 23:22:55     INFO -      rsp = 0x00007ffe23876780   r12 = 0x00000000020ac6c0
[task 2017-10-09T23:22:55.128Z] 23:22:55     INFO -      r13 = 0x00000000020ac6c0   r14 = 0x000000000218a470
[task 2017-10-09T23:22:55.128Z] 23:22:55     INFO -      r15 = 0x000000000218a300   rip = 0x00007fb555954306
[task 2017-10-09T23:22:55.129Z] 23:22:55     INFO -      Found by: call frame info
[task 2017-10-09T23:22:55.130Z] 23:22:55     INFO -   4  libxul.so!JS_DestroyContext [jsapi.cpp:2ed5e7fbf39e : 510 + 0x5]
[task 2017-10-09T23:22:55.131Z] 23:22:55     INFO -      rbx = 0x000000000218a308   rbp = 0x00007ffe23876820
[task 2017-10-09T23:22:55.131Z] 23:22:55     INFO -      rsp = 0x00007ffe23876820   r12 = 0x000000000218a3c0
[task 2017-10-09T23:22:55.132Z] 23:22:55     INFO -      r13 = 0x000000000218a408   r14 = 0x000000000218a470
[task 2017-10-09T23:22:55.132Z] 23:22:55     INFO -      r15 = 0x000000000218a300   rip = 0x00007fb555954701
[task 2017-10-09T23:22:55.133Z] 23:22:55     INFO -      Found by: call frame info
[task 2017-10-09T23:22:55.134Z] 23:22:55     INFO -   5  libxul.so!mozilla::CycleCollectedJSContext::~CycleCollectedJSContext [CycleCollectedJSContext.cpp:2ed5e7fbf39e : 99 + 0x13]
[task 2017-10-09T23:22:55.134Z] 23:22:55     INFO -      rbx = 0x000000000218a308   rbp = 0x00007ffe23876890
[task 2017-10-09T23:22:55.135Z] 23:22:55     INFO -      rsp = 0x00007ffe23876830   r12 = 0x000000000218a3c0
[task 2017-10-09T23:22:55.136Z] 23:22:55     INFO -      r13 = 0x000000000218a408   r14 = 0x000000000218a470
[task 2017-10-09T23:22:55.137Z] 23:22:55     INFO -      r15 = 0x000000000218a300   rip = 0x00007fb550eb46d1
[task 2017-10-09T23:22:55.137Z] 23:22:55     INFO -      Found by: call frame info
[task 2017-10-09T23:22:55.138Z] 23:22:55     INFO -   6  libxul.so!XPCJSContext::~XPCJSContext [XPCJSContext.cpp:2ed5e7fbf39e : 871 + 0x3a]
[task 2017-10-09T23:22:55.140Z] 23:22:55     INFO -      rbx = 0x000000000218a300   rbp = 0x00007ffe238768b0
[task 2017-10-09T23:22:55.140Z] 23:22:55     INFO -      rsp = 0x00007ffe238768a0   r12 = 0x0000000002029dc0
[task 2017-10-09T23:22:55.141Z] 23:22:55     INFO -      r13 = 0x0000000002063028   r14 = 0x00007fb550eed0b2
[task 2017-10-09T23:22:55.141Z] 23:22:55     INFO -      r15 = 0x00000000056a2cf0   rip = 0x00007fb551a151f4
[task 2017-10-09T23:22:55.142Z] 23:22:55     INFO -      Found by: call frame info


this is perma failing on code coverage builds- we do run code coverage builds in "debug" mode so we can accurately get all the information from each process, this is different as talos is only run in "opt" mode normally.

:jonco, do you have any ideas on how to solve this?
Flags: needinfo?(jcoppeard)
Component: Talos → JavaScript Engine
Product: Testing → Core
Version: Version 3 → unspecified
Well I guess that confirms the diagnosis in bug 1402473; this is just failing later on for the same reason.

It's this assertion failing:

    MOZ_ASSERT_IF(m_pools.initialized(), m_pools.empty()); 

It's strange we're not seeing the assertion message.  Maybe the log is getting truncated or something.
Similar fix as for the other bug.  Relax the assertion if the embedding leaked GC things at shutdown.

(These bugs are annoying.  I filed bug 1407593 for the root cause.)
Assignee: nobody → jcoppeard
Flags: needinfo?(jcoppeard)
Attachment #8917334 - Flags: review?(jdemooij)
Attachment #8917334 - Flags: review?(jdemooij) → review+
Pushed by jcoppeard@mozilla.com:
https://hg.mozilla.org/integration/mozilla-inbound/rev/3d373c760a7f
Relax assertion in ExecutableAllocator destructor if the embedding leaked r=jandem
https://hg.mozilla.org/mozilla-central/rev/3d373c760a7f
Status: NEW → RESOLVED
Closed: 2 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla58
now we have a new failure:
[task 2017-10-13T08:22:11.997Z] 08:22:11     INFO -   0  libxul.so!js::jit::ReleaseProcessExecutableMemory [ProcessExecutableMemory.cpp:23d2b8b32713 : 483 + 0x28]
[task 2017-10-13T08:22:11.997Z] 08:22:11     INFO -      rax = 0x00007ffc4f58b5b0   rdx = 0x0000000000000000
[task 2017-10-13T08:22:11.997Z] 08:22:11     INFO -      rcx = 0x00007f3edb0492ad   rbx = 0x00007ffc4f58b5a8
[task 2017-10-13T08:22:11.998Z] 08:22:11     INFO -      rsi = 0x00007f3edb318770   rdi = 0x00007f3edb317540
[task 2017-10-13T08:22:11.998Z] 08:22:11     INFO -      rbp = 0x00007ffc4f58b560   rsp = 0x00007ffc4f58b560
[task 2017-10-13T08:22:11.998Z] 08:22:11     INFO -       r8 = 0x00007f3edb318770    r9 = 0x00007f3edc3e0740
[task 2017-10-13T08:22:11.999Z] 08:22:11     INFO -      r10 = 0x0000000000000000   r11 = 0x0000000000000000
[task 2017-10-13T08:22:11.999Z] 08:22:11     INFO -      r12 = 0x00007ffc4f58b5b8   r13 = 0x00007ffc4f58b5b0
[task 2017-10-13T08:22:12.000Z] 08:22:11     INFO -      r14 = 0x00007f3ec1ccc49a   r15 = 0x0000000005c9c270
[task 2017-10-13T08:22:12.000Z] 08:22:11     INFO -      rip = 0x00007f3ec6535aa0
[task 2017-10-13T08:22:12.000Z] 08:22:12     INFO -      Found by: given as instruction pointer in context
[task 2017-10-13T08:22:12.000Z] 08:22:12     INFO -   1  libxul.so!JS_ShutDown [Initialization.cpp:23d2b8b32713 : 199 + 0x5]
[task 2017-10-13T08:22:12.001Z] 08:22:12     INFO -      rbx = 0x00007ffc4f58b5a8   rbp = 0x00007ffc4f58b570
[task 2017-10-13T08:22:12.001Z] 08:22:12     INFO -      rsp = 0x00007ffc4f58b570   r12 = 0x00007ffc4f58b5b8
[task 2017-10-13T08:22:12.001Z] 08:22:12     INFO -      r13 = 0x00007ffc4f58b5b0   r14 = 0x00007f3ec1ccc49a
[task 2017-10-13T08:22:12.001Z] 08:22:12     INFO -      r15 = 0x0000000005c9c270   rip = 0x00007f3ec6a9ded4
[task 2017-10-13T08:22:12.002Z] 08:22:12     INFO -      Found by: call frame info
[task 2017-10-13T08:22:12.002Z] 08:22:12     INFO -   2  libxul.so!mozilla::ShutdownXPCOM [XPCOMInit.cpp:23d2b8b32713 : 1023 + 0x5]
[task 2017-10-13T08:22:12.003Z] 08:22:12     INFO -      rbx = 0x00007ffc4f58b5a8   rbp = 0x00007ffc4f58b600
[task 2017-10-13T08:22:12.003Z] 08:22:12     INFO -      rsp = 0x00007ffc4f58b580   r12 = 0x00007ffc4f58b5b8
[task 2017-10-13T08:22:12.003Z] 08:22:12     INFO -      r13 = 0x00007ffc4f58b5b0   r14 = 0x00007f3ec1ccc49a
[task 2017-10-13T08:22:12.004Z] 08:22:12     INFO -      r15 = 0x0000000005c9c270   rip = 0x00007f3ec1d7ca06
[task 2017-10-13T08:22:12.004Z] 08:22:12     INFO -      Found by: call frame info


It seems like we fix one failure, then we find the next one, repeat.

:jonco, does it make sense to fix this failure as we have done in the past (and the next ones we see), or work on bug 1407593?
Flags: needinfo?(jcoppeard)
(In reply to Joel Maher ( :jmaher) (UTC-5) from comment #6)
Oh man.  I'll try and push on that bug.
Flags: needinfo?(jcoppeard)
New failure is being tracked in bug 1408403.
See Also: → 1408403
You need to log in before you can comment on or make changes to this bug.