Closed Bug 1636625 Opened 6 years ago Closed 5 years ago

Intermittent PROCESS-CRASH | automation.py | application crashed [@ js::SavedStacks::adoptAsyncStack(JSContext*, JS::MutableHandle<js::SavedFrame*>, JS::Handle<JSAtom*>, mozilla::Maybe<unsigned long> const&)]

Categories

(Core :: JavaScript Engine, defect)

Product:
Core
Component:
JavaScript Engine
Type:
defect

Tracking

()

Status:
RESOLVED INVALID

People

(Reporter: intermittent-bug-filer, Unassigned)

Details

(Keywords: crash, intermittent-failure)

Crash Data

Filed by: nbeleuzu [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer.html#?job_id=301486341&repo=autoland
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/ERkroRHXSwKNQHCfv8C_yg/runs/0/artifacts/public/logs/live_backing.log

[task 2020-05-08T23:32:05.721Z] 23:32:05 INFO - PROCESS-CRASH | automation.py | application crashed [@ js::SavedStacks::adoptAsyncStack(JSContext*, JS::MutableHandle<js::SavedFrame*>, JS::Handle<JSAtom*>, mozilla::Maybe<unsigned long> const&)]
[task 2020-05-08T23:32:05.721Z] 23:32:05 INFO - Crash dump filename: /var/folders/lf/_bkv06z97sz7lng1644cky_h000017/T/tmpiS3RuG.mozrunner/minidumps/1C8A947E-B371-4AAE-A996-2DE5C048C855.dmp
[task 2020-05-08T23:32:05.721Z] 23:32:05 INFO - Operating system: Mac OS X
[task 2020-05-08T23:32:05.721Z] 23:32:05 INFO - 10.14.5 18F132
[task 2020-05-08T23:32:05.721Z] 23:32:05 INFO - CPU: amd64
[task 2020-05-08T23:32:05.721Z] 23:32:05 INFO - family 6 model 69 stepping 1
[task 2020-05-08T23:32:05.721Z] 23:32:05 INFO - 4 CPUs
[task 2020-05-08T23:32:05.722Z] 23:32:05 INFO -
[task 2020-05-08T23:32:05.722Z] 23:32:05 INFO - GPU: UNKNOWN
[task 2020-05-08T23:32:05.722Z] 23:32:05 INFO -
[task 2020-05-08T23:32:05.722Z] 23:32:05 INFO - Crash reason: EXC_BAD_ACCESS / KERN_INVALID_ADDRESS
[task 2020-05-08T23:32:05.722Z] 23:32:05 INFO - Crash address: 0x2f47fce0
[task 2020-05-08T23:32:05.722Z] 23:32:05 INFO - Process uptime: 3 seconds
[task 2020-05-08T23:32:05.722Z] 23:32:05 INFO -
[task 2020-05-08T23:32:05.722Z] 23:32:05 INFO - Thread 0 (crashed)
[task 2020-05-08T23:32:05.722Z] 23:32:05 INFO - 0 XUL!js::SavedStacks::adoptAsyncStack(JSContext*, JS::MutableHandle<js::SavedFrame*>, JS::Handle<JSAtom*>, mozilla::Maybe<unsigned long> const&) [SavedStacks.cpp:220a0d9666fe4fd3f044efc527a47af63e473b57 : 1605 + 0x49]
[task 2020-05-08T23:32:05.722Z] 23:32:05 INFO - rax = 0x000000012c07f800 rdx = 0x000020a7b63b7940
[task 2020-05-08T23:32:05.722Z] 23:32:05 INFO - rcx = 0x00000000034004e0 rbx = 0x0000000000000000
[task 2020-05-08T23:32:05.722Z] 23:32:05 INFO - rsi = 0x000000012f47fce0 rdi = 0x00000b220d9d6fa0
[task 2020-05-08T23:32:05.722Z] 23:32:05 INFO - rbp = 0x00007ffee834e2e0 rsp = 0x00007ffee834de10
[task 2020-05-08T23:32:05.722Z] 23:32:05 INFO - r8 = 0x00000b220d9d6fa0 r9 = 0x00000b220d9d7150
[task 2020-05-08T23:32:05.722Z] 23:32:05 INFO - r10 = 0x0000000000000006 r11 = 0xfffa000000000000
[task 2020-05-08T23:32:05.722Z] 23:32:05 INFO - r12 = 0xfffe000000000000 r13 = 0xfff9800000000000
[task 2020-05-08T23:32:05.722Z] 23:32:05 INFO - r14 = 0xfffb000000000000 r15 = 0x00000b220d9d6f80
[task 2020-05-08T23:32:05.722Z] 23:32:05 INFO - rip = 0x0000000116fade4a
[task 2020-05-08T23:32:05.723Z] 23:32:05 INFO - Found by: given as instruction pointer in context
[task 2020-05-08T23:32:05.723Z] 23:32:05 INFO - 1 XUL!js::SavedStacks::saveCurrentStack(JSContext*, JS::MutableHandle<js::SavedFrame*>, mozilla::Variant<JS::AllFrames, JS::MaxFrames, JS::FirstSubsumedFrame>&&) [SavedStacks.cpp:220a0d9666fe4fd3f044efc527a47af63e473b57 : 1307 + 0x10f1]
[task 2020-05-08T23:32:05.723Z] 23:32:05 INFO - rbp = 0x00007ffee834ec90 rsp = 0x00007ffee834e2f0
[task 2020-05-08T23:32:05.723Z] 23:32:05 INFO - rip = 0x0000000116fac12e
[task 2020-05-08T23:32:05.723Z] 23:32:05 INFO - Found by: previous frame's frame pointer
[task 2020-05-08T23:32:05.723Z] 23:32:05 INFO - 2 XUL!PromiseDebugInfo::setResolutionInfo(JSContext*, JS::Handle<js::PromiseObject*>) [Promise.cpp:220a0d9666fe4fd3f044efc527a47af63e473b57 : 512 + 0x46]
[task 2020-05-08T23:32:05.723Z] 23:32:05 INFO - rbp = 0x00007ffee834ed90 rsp = 0x00007ffee834eca0
[task 2020-05-08T23:32:05.723Z] 23:32:05 INFO - rip = 0x0000000116e80d82
[task 2020-05-08T23:32:05.723Z] 23:32:05 INFO - Found by: previous frame's frame pointer
[task 2020-05-08T23:32:05.723Z] 23:32:05 INFO - 3 XUL!FulfillMaybeWrappedPromise(JSContext*, JS::Handle<JSObject*>, JS::Handle<JS::Value>) [Promise.cpp:220a0d9666fe4fd3f044efc527a47af63e473b57 : 1320 + 0xd5]
[task 2020-05-08T23:32:05.723Z] 23:32:05 INFO - rbp = 0x00007ffee834ee90 rsp = 0x00007ffee834eda0
[task 2020-05-08T23:32:05.723Z] 23:32:05 INFO - rip = 0x0000000116e9b9d6
[task 2020-05-08T23:32:05.723Z] 23:32:05 INFO - Found by: previous frame's frame pointer
[task 2020-05-08T23:32:05.723Z] 23:32:05 INFO - 4 XUL!ResolvePromiseInternal(JSContext*, JS::Handle<JSObject*>, JS::Handle<JS::Value>) [Promise.cpp:220a0d9666fe4fd3f044efc527a47af63e473b57 : 975 + 0x12]
[task 2020-05-08T23:32:05.724Z] 23:32:05 INFO - rbp = 0x00007ffee834f000 rsp = 0x00007ffee834eea0
[task 2020-05-08T23:32:05.724Z] 23:32:05 INFO - rip = 0x0000000116e7ab6c
[task 2020-05-08T23:32:05.724Z] 23:32:05 INFO - Found by: previous frame's frame pointer
[task 2020-05-08T23:32:05.724Z] 23:32:05 INFO - 5 XUL!ResolvePromiseFunction(JSContext*, unsigned int, JS::Value*) [Promise.cpp:220a0d9666fe4fd3f044efc527a47af63e473b57 : 1091 + 0xb]
[task 2020-05-08T23:32:05.724Z] 23:32:05 INFO - rbp = 0x00007ffee834f050 rsp = 0x00007ffee834f010
[task 2020-05-08T23:32:05.724Z] 23:32:05 INFO - rip = 0x0000000116e9ac3a
[task 2020-05-08T23:32:05.724Z] 23:32:05 INFO - Found by: previous frame's frame pointer
[task 2020-05-08T23:32:05.724Z] 23:32:05 INFO - 6 XUL!js::InternalCallOrConstruct(JSContext*, JS::CallArgs const&, js::MaybeConstruct, js::CallReason) [Interpreter.cpp:220a0d9666fe4fd3f044efc527a47af63e473b57 : 585 + 0x88]
[task 2020-05-08T23:32:05.724Z] 23:32:05 INFO - rbp = 0x00007ffee834f120 rsp = 0x00007ffee834f060
[task 2020-05-08T23:32:05.724Z] 23:32:05 INFO - rip = 0x0000000116d11fb3
[task 2020-05-08T23:32:05.724Z] 23:32:05 INFO - Found by: previous frame's frame pointer
[task 2020-05-08T23:32:05.724Z] 23:32:05 INFO - 7 XUL!js::jit::DoCallFallback(JSContext*, js::jit::BaselineFrame*, js::jit::ICCall_Fallback*, unsigned int, JS::Value*, JS::MutableHandle<JS::Value>) [BaselineIC.cpp:220a0d9666fe4fd3f044efc527a47af63e473b57 : 2990 + 0xaf]
[task 2020-05-08T23:32:05.724Z] 23:32:05 INFO - rbp = 0x00007ffee834f450 rsp = 0x00007ffee834f130
[task 2020-05-08T23:32:05.724Z] 23:32:05 INFO - rip = 0x000000011740f3ea
[task 2020-05-08T23:32:05.724Z] 23:32:05 INFO - Found by: previous frame's frame pointer
[task 2020-05-08T23:32:05.724Z] 23:32:05 INFO - 8 0x356382cb3bd8
[task 2020-05-08T23:32:05.725Z] 23:32:05 INFO - rbp = 0x00007ffee834f4c8 rsp = 0x00007ffee834f460
[task 2020-05-08T23:32:05.725Z] 23:32:05 INFO - rip = 0x0000356382cb3bd8
[task 2020-05-08T23:32:05.725Z] 23:32:05 INFO - Found by: previous frame's frame pointer
[task 2020-05-08T23:32:05.725Z] 23:32:05 INFO - 9 0x12665b4d8
[task 2020-05-08T23:32:05.725Z] 23:32:05 INFO - rbp = 0x00007ffee834f538 rsp = 0x00007ffee834f4d8
[task 2020-05-08T23:32:05.725Z] 23:32:05 INFO - rip = 0x000000012665b4d8
[task 2020-05-08T23:32:05.725Z] 23:32:05 INFO - Found by: previous frame's frame pointer
[task 2020-05-08T23:32:05.725Z] 23:32:05 INFO - 10 0x356382ccd30e
[task 2020-05-08T23:32:05.725Z] 23:32:05 INFO - rbp = 0x00007ffee834f568 rsp = 0x00007ffee834f548
[task 2020-05-08T23:32:05.725Z] 23:32:05 INFO - rip = 0x0000356382ccd30e
[task 2020-05-08T23:32:05.725Z] 23:32:05 INFO - Found by: previous frame's frame pointer

Because this bug's Severity is normal and has not been changed, and this bug's priority is -- (none,) indicating it has has not been previously triaged, the bug's Severity is being updated to -- (default, untriaged.)

Severity: normal → --

Kannan, Could you look a this Intermittent crash bug and see if it is actionable or not?

Severity: -- → S3
Flags: needinfo?(kvijayan)

Taking a look now.

Flags: needinfo?(kvijayan)

Did not make progress on this much before due to parser-atoms work. Taking a look again.

My gut on this suggests data corruption and single-bit memory flip. Given that there are no other stack crashes like this, and given the following:

Crash address: 0x2f47fce0

rax = 0x000000012c07f800 rdx = 0x000020a7b63b7940
rcx = 0x00000000034004e0 rbx = 0x0000000000000000
rsi = 0x000000012f47fce0 rdi = 0x00000b220d9d6fa0
rbp = 0x00007ffee834e2e0 rsp = 0x00007ffee834de10
r8 = 0x00000b220d9d6fa0 r9 = 0x00000b220d9d7150
r10 = 0x0000000000000006 r11 = 0xfffa000000000000
r12 = 0xfffe000000000000 r13 = 0xfff9800000000000
r14 = 0xfffb000000000000 r15 = 0x00000b220d9d6f80

Note that the crash address is almost held in rsi, except for a single bit at bit 32. There's an address in a area of memory in rax.

The crash address itself is very low for a 64-bit memory space, possibly kernel memory space. After some digging, the mac-osx process memory layout includes this: VM_MAX_KERNEL_ADDRESS 0xDFFF_FFFF.

The crash address is below the kernel memory boundary, and reaching into kernel space.

Looking at the crash stack, and the location - it's happening during the 'emplaceBack' into a rooted GCVector that has been freshly allocated from the code. If the value in rsi is taken as an address, it's above the kernel memory space and more plausibly in user heap space, which is where the GCVector contents would be.

The culprit very strongly seems to be bit 32 getting cleared in the address before it gets dereferenced. We could possibly take a look at a disassembly here, but even without that this seems to point to some issue where a bit got flipped in the CPU and the write address got clobbered mid-flight.

The long-shot chance is that there is some issue here in the underlying code which causes this (e.g. that the pointer goes through some ptr => uint32 => ptr conversion and loses its high bits).. but let's keep in mind that this is very core Vector code that is used across the browser, and a bug as serious as "dropping bit 32 of the vector contents pointer sometimes" would show up way more frequently than this lone wolf bug.

Status: NEW → RESOLVED
Closed: 5 years ago
Resolution: --- → INVALID
You need to log in before you can comment on or make changes to this bug.