1732411 - Intermittent telemetry/marionette/tests/client/test_event_ping.py TestEventPing.test_event_ping | application crashed [@ js::InterpreterFrame::prologue(JSContext*)]

Status: RESOLVED FIXED

(Core :: JavaScript Engine, defect)

Description

[Treeherder Bug Filer]

Filed by: smolnar [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=352614849&repo=mozilla-central
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/f9wxpot9SdGOE1oME43rSA/runs/0/artifacts/public/logs/live_backing.log

---

INFO - mozcrash Copy/paste: /opt/worker/tasks/task_163243900159389/fetches/minidump_stackwalk/minidump_stackwalk /opt/worker/tasks/task_163243900159389/build/tmp__xwfsh9.mozrunner/minidumps/CA18DD0F-3A3B-48C9-A71A-322E25EAF01C.dmp /var/folders/pg/b483c4nn7qx88z7b70hpknvm000014/T/tmp7oa5p6m6
[task 2021-09-23T23:29:59.315Z] 23:29:59     INFO - mozcrash Saved minidump as /opt/worker/tasks/task_163243900159389/build/blobber_upload_dir/CA18DD0F-3A3B-48C9-A71A-322E25EAF01C.dmp
[task 2021-09-23T23:29:59.316Z] 23:29:59     INFO - mozcrash Saved app info as /opt/worker/tasks/task_163243900159389/build/blobber_upload_dir/CA18DD0F-3A3B-48C9-A71A-322E25EAF01C.extra
[task 2021-09-23T23:29:59.581Z] 23:29:59     INFO - PROCESS-CRASH | telemetry/marionette/tests/client/test_event_ping.py TestEventPing.test_event_ping | application crashed [@ js::InterpreterFrame::prologue(JSContext*)]
[task 2021-09-23T23:29:59.581Z] 23:29:59     INFO - Mozilla crash reason: MOZ_RELEASE_ASSERT(idx < storage_.size())
[task 2021-09-23T23:29:59.581Z] 23:29:59     INFO - Crash dump filename: /opt/worker/tasks/task_163243900159389/build/tmp__xwfsh9.mozrunner/minidumps/CA18DD0F-3A3B-48C9-A71A-322E25EAF01C.dmp
[task 2021-09-23T23:29:59.581Z] 23:29:59     INFO - Operating system: Mac OS X
[task 2021-09-23T23:29:59.581Z] 23:29:59     INFO -                   10.15.7 19H524
[task 2021-09-23T23:29:59.581Z] 23:29:59     INFO - CPU: amd64
[task 2021-09-23T23:29:59.581Z] 23:29:59     INFO -      family 6 model 158 stepping 10
[task 2021-09-23T23:29:59.581Z] 23:29:59     INFO -      12 CPUs
[task 2021-09-23T23:29:59.582Z] 23:29:59     INFO - 
[task 2021-09-23T23:29:59.582Z] 23:29:59     INFO - GPU: UNKNOWN
[task 2021-09-23T23:29:59.582Z] 23:29:59     INFO - 
[task 2021-09-23T23:29:59.582Z] 23:29:59     INFO - Crash reason:  EXC_BAD_ACCESS / KERN_INVALID_ADDRESS
[task 2021-09-23T23:29:59.582Z] 23:29:59     INFO - Crash address: 0x0
[task 2021-09-23T23:29:59.582Z] 23:29:59     INFO - Process uptime: 16 seconds
[task 2021-09-23T23:29:59.582Z] 23:29:59     INFO - 
[task 2021-09-23T23:29:59.582Z] 23:29:59     INFO - Thread 0 tid 775 (crashed) - GeckoMain 0  XUL!js::InitFunctionEnvironmentObjects(JSContext*, js::AbstractFramePtr) [EnvironmentObject.cpp:4eda9eb8926bdd50f4b80128ce3475eb7c6d9a4d : 3934 + 0x617]
[task 2021-09-23T23:29:59.582Z] 23:29:59     INFO -     rax = 0x000000010fd955bb   rdx = 0x000000000000000e
[task 2021-09-23T23:29:59.582Z] 23:29:59     INFO -     rcx = 0x00000001082983d8   rbx = 0x000000011b722000
[task 2021-09-23T23:29:59.582Z] 23:29:59     INFO -     rsi = 0x00000000e5e5e5e5   rdi = 0x000000011b722000
[task 2021-09-23T23:29:59.582Z] 23:29:59     INFO -     rbp = 0x00007ffee79eff50   rsp = 0x00007ffee79efe20
[task 2021-09-23T23:29:59.582Z] 23:29:59     INFO -      r8 = 0x0000000320700030    r9 = 0x0000000000000002
[task 2021-09-23T23:29:59.582Z] 23:29:59     INFO -     r10 = 0x0000000000001012   r11 = 0x0000000000000202
[task 2021-09-23T23:29:59.582Z] 23:29:59     INFO -     r12 = 0x0000000000000001   r13 = 0x0000000320700039
[task 2021-09-23T23:29:59.582Z] 23:29:59     INFO -     r14 = 0x000000011b722018   r15 = 0x00000000e79f00f2
[task 2021-09-23T23:29:59.582Z] 23:29:59     INFO -     rip = 0x0000000109e24426
[task 2021-09-23T23:29:59.582Z] 23:29:59     INFO -     Found by: given as instruction pointer in context
[task 2021-09-23T23:29:59.582Z] 23:29:59     INFO -  1  XUL!js::InterpreterFrame::prologue(JSContext*) [Stack.cpp:4eda9eb8926bdd50f4b80128ce3475eb7c6d9a4d : 200 + 0xf]
[task 2021-09-23T23:29:59.582Z] 23:29:59     INFO -     rbx = 0x000000011b722000   rbp = 0x00007ffee79effa0
[task 2021-09-23T23:29:59.582Z] 23:29:59     INFO -     rsp = 0x00007ffee79eff60   r12 = 0x000000011b763130
[task 2021-09-23T23:29:59.582Z] 23:29:59     INFO -     r13 = 0x0000000000000000   r14 = 0x0000000320700038
[task 2021-09-23T23:29:59.582Z] 23:29:59     INFO -     r15 = 0x00000000e79f00f2   rip = 0x0000000109f19172
[task 2021-09-23T23:29:59.583Z] 23:29:59     INFO -     Found by: call frame info
[task 2021-09-23T23:29:59.583Z] 23:29:59     INFO -  2  XUL!Interpret(JSContext*, js::RunState&) [Interpreter.cpp:4eda9eb8926bdd50f4b80128ce3475eb7c6d9a4d : 3309 + 0x13]
[task 2021-09-23T23:29:59.583Z] 23:29:59     INFO -     rbx = 0x0000000320700038   rbp = 0x00007ffee79f0400
INFO -     rsp = 0x00007ffee79effb0   r12 = 0x000000011b763130
[task 2021-09-23T23:29:59.583Z] 23:29:59     INFO -     r13 = 0x0000000000000000   r14 = 0x00000003207000a8
[task 2021-09-23T23:29:59.583Z] 23:29:59     INFO -     r15 = 0x00000000e79f00f2   rip = 0x0000000109d85420
[task 2021-09-23T23:29:59.583Z] 23:29:59     INFO -     Found by: call frame info
[task 2021-09-23T23:29:59.583Z] 23:29:59     INFO -  3  XUL!js::InternalCallOrConstruct(JSContext*, JS::CallArgs const&, js::MaybeConstruct, js::CallReason) [Interpreter.cpp:4eda9eb8926bdd50f4b80128ce3475eb7c6d9a4d : 504 + 0x18]
[task 2021-09-23T23:29:59.583Z] 23:29:59     INFO -     rbx = 0x0000000000000001   rbp = 0x00007ffee79f04f0
[task 2021-09-23T23:29:59.583Z] 23:29:59     INFO -     rsp = 0x00007ffee79f0410   r12 = 0x00002263f8cc91a0
[task 2021-09-23T23:29:59.583Z] 23:29:59     INFO -     r13 = 0x0000000000000000   r14 = 0x000000011b70b000
[task 2021-09-23T23:29:59.583Z] 23:29:59     INFO -     r15 = 0x0000000000000000   rip = 0x0000000109d8f87e
[task 2021-09-23T23:29:59.583Z] 23:29:59     INFO -     Found by: call frame info
[task 2021-09-23T23:29:59.583Z] 23:29:59     INFO -  4  XUL!js::Call(JSContext*, JS::Handle<JS::Value>, JS::Handle<JS::Value>, js::AnyInvokeArgs const&, JS::MutableHandle<JS::Value>, js::CallReason) [Interpreter.cpp:4eda9eb8926bdd50f4b80128ce3475eb7c6d9a4d : 549 + 0x92]
[task 2021-09-23T23:29:59.583Z] 23:29:59     INFO -     rbx = 0x00007ffee79f0578   rbp = 0x00007ffee79f0530
[task 2021-09-23T23:29:59.583Z] 23:29:59     INFO -     rsp = 0x00007ffee79f0500   r12 = 0x000000011b722000
[task 2021-09-23T23:29:59.583Z] 23:29:59     INFO -     r13 = 0xfffe000000000000   r14 = 0x000000011b763090
[task 2021-09-23T23:29:59.583Z] 23:29:59     INFO -     r15 = 0x0000000000000000   rip = 0x0000000109d9161a
[task 2021-09-23T23:29:59.583Z] 23:29:59     INFO -     Found by: call frame info
[task 2021-09-23T23:29:59.583Z] 23:29:59     INFO -  5  XUL!js::fun_apply(JSContext*, unsigned int, JS::Value*) [JSFunction.cpp:4eda9eb8926bdd50f4b80128ce3475eb7c6d9a4d : 1011 + 0x15]
[task 2021-09-23T23:29:59.583Z] 23:29:59     INFO -     rbx = 0x0000000000000002   rbp = 0x00007ffee79f0630
[task 2021-09-23T23:29:59.583Z] 23:29:59     INFO -     rsp = 0x00007ffee79f0540   r12 = 0x0000000000000000
[task 2021-09-23T23:29:59.583Z] 23:29:59     INFO -     r13 = 0x000000011b722000   r14 = 0x000000011b763090
[task 2021-09-23T23:29:59.583Z] 23:29:59     INFO -     r15 = 0xfff9800000000000   rip = 0x0000000109e96ee6
[task 2021-09-23T23:29:59.584Z] 23:29:59     INFO -     Found by: call frame info
[task 2021-09-23T23:29:59.584Z] 23:29:59     INFO -  6  XUL!js::InternalCallOrConstruct(JSContext*, JS::CallArgs const&, js::MaybeConstruct, js::CallReason) [Interpreter.cpp:4eda9eb8926bdd50f4b80128ce3475eb7c6d9a4d : 472 + 0x1c8]
[task 2021-09-23T23:29:59.584Z] 23:29:59     INFO -     rbx = 0x00007ffee79f0868   rbp = 0x00007ffee79f0720
[task 2021-09-23T23:29:59.584Z] 23:29:59     INFO -     rsp = 0x00007ffee79f0640   r12 = 0xffff800000000000
[task 2021-09-23T23:29:59.584Z] 23:29:59     INFO -     r13 = 0xfffb000000000000   r14 = 0x000000011b70b000
[task 2021-09-23T23:29:59.584Z] 23:29:59     INFO -     r15 = 0xfffe000000000000   rip = 0x0000000109d8f299
[task 2021-09-23T23:29:59.584Z] 23:29:59     INFO -     Found by: call frame info
[task 2021-09-23T23:29:59.584Z] 23:29:59     INFO -  7  XUL!Interpret(JSContext*, js::RunState&) [Interpreter.cpp:4eda9eb8926bdd50f4b80128ce3475eb7c6d9a4d : 3239 + 0x8a]
[task 2021-09-23T23:29:59.584Z] 23:29:59     INFO -     rbx = 0x000000011b7630a0   rbp = 0x00007ffee79f0b80
[task 2021-09-23T23:29:59.584Z] 23:29:59     INFO -     rsp = 0x00007ffee79f0730   r12 = 0xfffb000000000000
[task 2021-09-23T23:29:59.584Z] 23:29:59     INFO -     r13 = 0x0000000000000000   r14 = 0xfffdffffffffffff
[task 2021-09-23T23:29:59.584Z] 23:29:59     INFO -     r15 = 0x000000001b762ff4   rip = 0x0000000109d855b0
[task 2021-09-23T23:29:59.584Z] 23:29:59     INFO -     Found by: call frame info
[task 2021-09-23T23:29:59.584Z] 23:29:59     INFO -  8  XUL!js::InternalCallOrConstruct(JSContext*, JS::CallArgs const&, js::MaybeConstruct, js::CallReason) [Interpreter.cpp:4eda9eb8926bdd50f4b80128ce3475eb7c6d9a4d : 504 + 0x18]
[task 2021-09-23T23:29:59.584Z] 23:29:59     INFO -     rbx = 0x0000000000000000   rbp = 0x00007ffee79f0c70
[task 2021-09-23T23:29:59.584Z] 23:29:59     INFO -     rsp = 0x00007ffee79f0b90   r12 = 0x00002b30c420d240
[task 2021-09-23T23:29:59.584Z] 23:29:59     INFO -     r13 = 0x0000000000000000   r14 = 0x000000011b70b000
[task 2021-09-23T23:29:59.584Z] 23:29:59     INFO -     r15 = 0x0000008ffea37654   rip = 0x0000000109d8f87e
[task 2021-09-23T23:29:59.584Z] 23:29:59     INFO -     Found by: call frame info
INFO -  9  XUL!JS_CallFunctionValue(JSContext*, JS::Handle<JSObject*>, JS::Handle<JS::Value>, JS::HandleValueArray const&, JS::MutableHandle<JS::Value>) [CallAndConstruct.cpp:4eda9eb8926bdd50f4b80128ce3475eb7c6d9a4d : 53 + 0xb3]
[task 2021-09-23T23:29:59.584Z] 23:29:59     INFO -     rbx = 0xfffe000000000000   rbp = 0x00007ffee79f0d70
[task 2021-09-23T23:29:59.584Z] 23:29:59     INFO -     rsp = 0x00007ffee79f0c80   r12 = 0xfffa800000000000
[task 2021-09-23T23:29:59.585Z] 23:29:59     INFO -     r13 = 0x0000000000000001   r14 = 0x000000011b722000
[task 2021-09-23T23:29:59.585Z] 23:29:59     INFO -     r15 = 0x0000000000000001   rip = 0x0000000109e0d82c
[task 2021-09-23T23:29:59.585Z] 23:29:59     INFO -     Found by: call frame info
[task 2021-09-23T23:29:59.585Z] 23:29:59     INFO - 10  XUL!nsXPCWrappedJS::CallMethod(unsigned short, nsXPTMethodInfo const*, nsXPTCMiniVariant*) [XPCWrappedJSClass.cpp:4eda9eb8926bdd50f4b80128ce3475eb7c6d9a4d : 973 + 0x32]

Comment 1

[Andrew McCreight [:mccr8]]

Note that the actual crash here is a bounds check assertion: MOZ_RELEASE_ASSERT(idx < storage_.size())

Although I think this was flagged because of the poison value in rsi.

Bug 1732400 is another recent interpreter-ish intermittent failure with a poison value in a register. I don't know if it is related.

Comment 2

[Jan de Mooij [:jandem]]

I think this was also a regression from bug 1732168. It looks Stencil-related and it happened between landing and back out of that change.

arai, can you please close this bug if you agree?

Comment 3

[Tooru Fujisawa [:arai]]

Yes, I agree.

the lifetime model used in the patch was wrong and it crashes after freeing bytecode for chrome-priv code,
that happens during/after XPCOM Shutdown.

Comment 4

[Andrew McCreight [:mccr8]]

Thanks for following up on these two bugs! These two reports were out-of-the-ordinary so it is nice to understand what happened, and that the issue was fixed.