1667336 - [warp] Hit MOZ_CRASH(Mutex ordering violation) at threading/Mutex.cpp:32

Status: VERIFIED FIXED

(Core :: JavaScript: GC, defect, P1)

Description

[Christian Holler (:decoder)]

The following testcase crashes on mozilla-central revision 20200923-7927a1705247 (debug build, run with --fuzzing-safe --cpu-count=2 --ion-offthread-compile=off --warp):

var g = newGlobal();
gczeal(9, 1);
gczeal(11, 2);
g.offThreadCompileScript("")
loadFile();
setJitCompilerOption("offthread-compilation.enable", 1);
while(true) { loadFile(); }
function loadFile() {
  try {
    x;
  } catch(exc) {}
}

Backtrace:

received signal SIGSEGV, Segmentation fault.
#0  js::Mutex::preLockChecks (this=0x7ffff605e1f0) at js/src/threading/Mutex.cpp:32
#1  js::Mutex::lock (this=0x7ffff605e1f0) at js/src/threading/Mutex.cpp:19
#2  0x0000555556fd9c21 in js::AtomsTable::AutoLock::AutoLock (this=<optimized out>, rt=0x7ffff6029000, aLock=...) at js/src/vm/JSAtom.cpp:338
#3  js::AtomsTable::atomIsPinned (this=0x7ffff6019680, rt=0x7ffff6029000, atom=0x3d48c239bd20) at js/src/vm/JSAtom.cpp:1018
#4  0x000055555759c947 in js::gc::AtomMarkingRuntime::atomIsMarked<JSAtom> (this=<optimized out>, zone=0x7ffff5afb000, thing=0x3d48c239bd20) at js/src/gc/AtomMarking.cpp:220
#5  0x000055555766d4a6 in CheckTraversedEdge<js::Shape*, JSString> (source=source@entry=0x3d48c239e560, target=0x3d48c239bd20) at js/src/gc/Marking.cpp:1121
#6  js::GCMarker::traverseEdge<js::Shape*, JSString> (this=this@entry=0x7ffff602a3d0, source=source@entry=0x3d48c239e560, target=0x3d48c239bd20) at js/src/gc/Marking.cpp:1141
#7  0x000055555766cded in _ZZN2js8GCMarker12traverseEdgeIPNS_5ShapeEN2JS11PropertyKeyEEEvT_RKT0_ENKUlS6_E_clIP8JSStringEEDaS6_ (this=<optimized out>, t=0x0) at js/src/gc/Marking.cpp:1148
#8  _ZZN2js17ApplyGCThingTypedIZNS_8GCMarker12traverseEdgeIPNS_5ShapeEN2JS11PropertyKeyEEEvT_RKT0_EUlS7_E_EEbRKS6_OS7_ENKUlS7_E_clIP8JSStringEEDaS7_ (this=<optimized out>, t=0x0) at dist/include/js/Id.h:292
#9  _ZN2js15MapGCThingTypedIZNS_17ApplyGCThingTypedIZNS_8GCMarker12traverseEdgeIPNS_5ShapeEN2JS11PropertyKeyEEEvT_RKT0_EUlS8_E_EEbRKS7_OS8_EUlS8_E_EEDaSE_SF_ (id=..., f=<optimized out>) at dist/include/js/Id.h:276
#10 _ZN2js17ApplyGCThingTypedIZNS_8GCMarker12traverseEdgeIPNS_5ShapeEN2JS11PropertyKeyEEEvT_RKT0_EUlS7_E_EEbRKS6_OS7_ (id=..., f=<optimized out>) at dist/include/js/Id.h:290
#11 js::GCMarker::traverseEdge<js::Shape*, JS::PropertyKey> (this=0x7ffff602a3d0, source=0x3d48c239e560, thing=...) at js/src/gc/Marking.cpp:1147
#12 js::GCMarker::eagerlyMarkChildren (this=this@entry=0x7ffff602a3d0, shape=0x3d48c239e560, shape@entry=0x3d48c239e240) at js/src/gc/Marking.cpp:1262
#13 0x000055555765c785 in js::GCMarker::markAndScan<js::Shape> (this=0x7ffff602a3d0, thing=0x3d48c239e240) at js/src/gc/Marking.cpp:1052
#14 js::GCMarker::traverse<js::Shape*> (this=0x7ffff602a3d0, thing=0x3d48c239e240) at js/src/gc/Marking.cpp:1062
#15 DoMarking<js::Shape> (gcmarker=0x7ffff602a3d0, thing=0x3d48c239e240) at js/src/gc/Marking.cpp:969
#16 0x000055555765c567 in js::gc::TraceEdgeInternal<js::Shape*> (trc=0x7ffff7104540 <_IO_2_1_stderr_>, trc@entry=0x7ffff602a3d0, thingp=thingp@entry=0x7fffffffa3d8, name=0x0) at js/src/gc/Marking.cpp:697
#17 0x000055555787f7f8 in js::TraceManuallyBarrieredEdge<js::Shape*> (trc=0x7ffff602a3d0, thingp=0x7fffffffa3d8, name=0x0) at js/src/gc/Tracer.h:222
#18 TraceWarpGCPtr<js::Shape*> (trc=0x7ffff602a3d0, thing=..., name=0x0) at js/src/jit/WarpSnapshot.cpp:202
#19 TraceWarpStubPtr<js::Shape> (trc=0x7ffff602a3d0, word=67382705513024, name=<optimized out>) at js/src/jit/WarpSnapshot.cpp:310
#20 js::jit::WarpCacheIR::traceData (this=this@entry=0x7ffff58e1608, trc=0x7ffff602a3d0) at js/src/jit/WarpSnapshot.cpp:327
#21 0x000055555787f0c2 in js::jit::WarpOpSnapshot::trace (this=this@entry=0x7ffff58e1608, trc=0x7ffff7105770 <_IO_stdfile_2_lock>, trc@entry=0x7ffff602a3d0) at js/src/jit/WarpSnapshot.cpp:256
#22 0x000055555787eed0 in js::jit::WarpScriptSnapshot::trace (this=this@entry=0x7ffff58e1828, trc=trc@entry=0x7ffff602a3d0) at js/src/jit/WarpSnapshot.cpp:238
#23 0x000055555787ec70 in js::jit::WarpSnapshot::trace (this=0x7ffff58e18a8, trc=0x7ffff602a3d0) at js/src/jit/WarpSnapshot.cpp:208
#24 0x0000555556fa63dc in js::GlobalHelperThreadState::trace (this=<optimized out>, trc=0x7ffff602a3d0) at js/src/vm/HelperThreads.cpp:2477
#25 0x0000555557653959 in js::gc::GCRuntime::traceRuntimeCommon (this=this@entry=0x7ffff6029740, trc=<optimized out>, trc@entry=0x7ffff602a3d0, traceOrMark=traceOrMark@entry=js::gc::GCRuntime::MarkRuntime) at js/src/gc/RootMarking.cpp:391
#26 0x00005555576533a8 in js::gc::GCRuntime::traceRuntimeForMajorGC (this=0x7ffff6029740, trc=0x7ffff602a3d0, session=...) at js/src/gc/RootMarking.cpp:282
#27 0x000055555768b04e in js::gc::MarkingValidator::nonIncrementalMark (this=<optimized out>, session=...) at js/src/gc/Verifier.cpp:599
#28 0x00005555575d3a77 in js::gc::GCRuntime::beginSweepPhase (this=this@entry=0x7ffff6029740, reason=<optimized out>, session=...) at js/src/gc/GC.cpp:5566
#29 0x00005555575db920 in js::gc::GCRuntime::incrementalSlice (this=this@entry=0x7ffff6029740, budget=..., gckind=..., reason=<optimized out>, reason@entry=JS::GCReason::DEBUG_GC, session=...) at js/src/gc/GC.cpp:6822
#30 0x00005555575de40a in js::gc::GCRuntime::gcCycle (this=this@entry=0x7ffff6029740, nonincrementalByAPI=true, budget=..., gckind=..., reason=reason@entry=JS::GCReason::DEBUG_GC) at js/src/gc/GC.cpp:7238
#31 0x00005555575dff79 in js::gc::GCRuntime::collect (this=0x7ffff6029740, nonincrementalByAPI=false, budget=..., gckindArg=..., reason=reason@entry=JS::GCReason::DEBUG_GC) at js/src/gc/GC.cpp:7473
#32 0x00005555575e56c2 in js::gc::GCRuntime::runDebugGC (this=this@entry=0x7ffff6029740) at js/src/gc/GC.cpp:8064
#33 0x0000555557593ce3 in js::gc::GCRuntime::gcIfNeededAtAllocation (this=this@entry=0x7ffff6029740, cx=0x7ffff6027000, cx@entry=0x20) at js/src/gc/Allocator.cpp:445
#34 js::gc::GCRuntime::checkAllocatorState<(js::AllowGC)1> (this=this@entry=0x7ffff6029740, cx=cx@entry=0x7ffff6027000, kind=kind@entry=js::gc::AllocKind::STRING) at js/src/gc/Allocator.cpp:407
#35 0x0000555557595e49 in js::AllocateStringImpl<JSString, (js::AllowGC)1> (cx=cx@entry=0x7ffff6027000, heap=js::gc::DefaultHeap) at js/src/gc/Allocator.cpp:210
#36 0x0000555557165a61 in js::AllocateString<JSThinInlineString, (js::AllowGC)1> (cx=0x7ffff6027000, heap=js::gc::DefaultHeap) at js/src/gc/Allocator.h:61
#37 JSThinInlineString::new_<(js::AllowGC)1> (cx=0x7ffff6027000, heap=js::gc::DefaultHeap) at js/src/vm/StringType-inl.h:322
#38 js::AllocateInlineString<(js::AllowGC)1, unsigned char> (cx=0x7ffff6027000, len=16, chars=<optimized out>, heap=js::gc::DefaultHeap) at js/src/vm/StringType-inl.h:35
#39 js::NewInlineString<(js::AllowGC)1, unsigned char> (cx=0x7ffff6027000, chars=..., heap=js::gc::DefaultHeap) at js/src/vm/StringType-inl.h:63
#40 js::NewStringCopyNDontDeflate<(js::AllowGC)1, unsigned char> (cx=cx@entry=0x7ffff6027000, s=0x7ffff5afa220 "x is not defined", n=16, heap=js::gc::DefaultHeap) at js/src/vm/StringType.cpp:1749
#41 0x0000555557166469 in js::NewStringCopyN<(js::AllowGC)1, unsigned char> (cx=0x7ffff6027000, s=0x7ffff7105770 <_IO_stdfile_2_lock> "", n=0, heap=js::gc::DefaultHeap) at js/src/vm/StringType.cpp:1828
#42 js::NewStringCopyUTF8N<(js::AllowGC)1> (cx=cx@entry=0x7ffff6027000, utf8=..., heap=heap@entry=js::gc::DefaultHeap) at js/src/vm/StringType.cpp:1865
#43 0x0000555556dfb7ea in js::NewStringCopyUTF8Z<(js::AllowGC)1> (cx=0x7ffff6027000, utf8=..., heap=js::gc::DefaultHeap) at js/src/vm/StringType.h:1548
#44 JS_NewStringCopyUTF8Z (cx=cx@entry=0x7ffff6027000, s=...) at js/src/jsapi.cpp:4121
#45 0x0000555556e0b2ed in JSErrorBase::newMessageString (this=0x7fffffffaea0, cx=0x7ffff6027000) at js/src/jsapi.cpp:4974
#46 js::ErrorToException (cx=cx@entry=0x7ffff6027000, reportp=reportp@entry=0x7fffffffaea0, callback=<optimized out>, callback@entry=0x555556ef9950 <js::GetErrorMessage(void*, unsigned int)>, userRef=userRef@entry=0x0) at js/src/jsexn.cpp:316
#47 0x0000555556effb4f in ReportError (cx=0x7ffff6027000, reportp=0x7fffffffaea0, callback=0x555556ef9950 <js::GetErrorMessage(void*, unsigned int)>, userRef=0x0) at js/src/vm/ErrorReporting.cpp:164
#48 js::ReportErrorNumberVA (cx=cx@entry=0x7ffff6027000, isWarning=isWarning@entry=js::IsWarning::No, callback=callback@entry=0x555556ef9950 <js::GetErrorMessage(void*, unsigned int)>, userRef=userRef@entry=0x0, errorNumber=errorNumber@entry=1, argumentsType=<optimized out>, argumentsType@entry=js::ArgumentsAreUTF8, ap=0x7fffffffb000) at js/src/vm/ErrorReporting.cpp:477
#49 0x0000555556ddbd6f in JS_ReportErrorNumberUTF8VA (cx=<optimized out>, errorCallback=<optimized out>, userRef=<optimized out>, errorNumber=<optimized out>, ap=0x7fffffffb000) at js/src/jsapi.cpp:4752
#50 JS_ReportErrorNumberUTF8 (cx=cx@entry=0x7ffff6027000, errorCallback=0x555556ef9950 <js::GetErrorMessage(void*, unsigned int)>, userRef=userRef@entry=0x0, errorNumber=errorNumber@entry=1) at js/src/jsapi.cpp:4742
#51 0x0000555556fdf2a5 in js::ReportIsNotDefined (cx=0x7ffff6027000, id=...) at js/src/vm/JSContext.cpp:518
#52 js::ReportIsNotDefined (cx=cx@entry=0x7ffff6027000, name=...) at js/src/vm/JSContext.cpp:525
#53 0x0000555556cd6a9e in js::FetchName<(js::GetNameMode)0> (cx=cx@entry=0x7ffff6027000, receiver=receiver@entry=..., holder=..., holder@entry=..., name=..., name@entry=..., prop=..., prop@entry=..., vp=...) at js/src/vm/Interpreter-inl.h:145
#54 0x0000555556d09102 in js::GetEnvironmentName<(js::GetNameMode)0> (cx=0x7ffff6027000, envChain=..., name=..., vp=...) at js/src/vm/Interpreter-inl.h:220
#55 0x0000555557752c9d in js::jit::DoGetNameFallback (cx=<optimized out>, frame=0x7fffffffb4d0, stub=<optimized out>, envChain=..., res=...) at js/src/jit/BaselineIC.cpp:2449
#56 0x000032d78883478f in ?? ()
[...]
#73 0x0000000000000000 in ?? ()
rax	0x55555592f648	93824996275784
rbx	0x7ffff605e1f0	140737320968688
rcx	0x555558510d08	93825042287880
rdx	0x0	0
rsi	0x7ffff7105770	140737338431344
rdi	0x7ffff7104540	140737338426688
rbp	0x7fffffffa250	140737488331344
rsp	0x7fffffffa240	140737488331328
r8	0x7ffff7105770	140737338431344
r9	0x7ffff7f99e00	140737353719296
r10	0x58	88
r11	0x7ffff6dac7a0	140737334921120
r12	0x3d48c239bd20	67382705503520
r13	0x0	0
r14	0x7ffff6029000	140737320751104
r15	0x7ffff6019680	140737320687232
rip	0x555556e6025c <js::Mutex::lock()+140>
=> 0x555556e6025c <js::Mutex::lock()+140>:	movl   $0x20,0x0
   0x555556e60267 <js::Mutex::lock()+151>:	callq  0x555556befa82 <abort()>

Not sure if this is shell-only or not, but there is GC involved and the testcase is somewhat fragile, so marking s-s until this has been investigated.

Comment 1

[Christian Holler (:decoder)]

Attachment: Testcase

Comment 2

[Jason Kratzer [:jkratzer]]

Bugmon Analysis:
Verified bug as reproducible on mozilla-central 20200925094208-8734082cd6de.
The bug appears to have been introduced in the following build range:

Start: b74ab1682deaf69e9d0eac0fb9c29e7e7a5a7a0b (20200902095359)
End: 237e445d595ee45bf684a879397377036c26da49 (20200902074535)
Pushlog: https://hg.mozilla.org/mozilla-unified/pushloghtml?fromchange=b74ab1682deaf69e9d0eac0fb9c29e7e7a5a7a0b&tochange=237e445d595ee45bf684a879397377036c26da49

Comment 3

[Jon Coppeard (:jonco)]

"Attempt to acquire mutex AtomsTable with order 227 while holding GlobalHelperThreadState with order 400"

Comment 4

[Jon Coppeard (:jonco)]

The lock is only taken by a check in debug builds. This is not security sensitive.

Comment 5

[Jon Coppeard (:jonco)]

Attachment: Bug 1667336 - Don't check atom marking when GC marking if the current thread holds the helper thread mutex r?sfink

Currently we require taking a lock when we make the check that traced atoms are
marked in the atoms marking bitmap. This causes problems if we already hold
another mutex with a lower mutex order - e.g. the helper thread lock.

This fix is to skip this check if we hold this mutex. In future (when the
stencil work lands) we may not need to take the atoms lock and we can remove
this check.

One complication was the logic in Mutex::ownedByCurrentThread which had a race
between checking whther the owning thread ID (defined as a Maybe<ThreadId>) had
a value and if so whether the value was that of the current thread. If the
mutext is held by another thread and then released we can attempt to get the
value when the Maybe is nothing, causing an assertion failure. The ThreadId
type already has a null value however so we can use that without wrapping it in
a Maybe.

Comment 6

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/05176b3f8dcb
Don't check atom marking when GC marking if the current thread holds the helper thread mutex r=sfink

Comment 7

[Jan de Mooij [:jandem]]

Thanks for fixing this, jonco!

Comment 8

[Cosmin Sabou [:CosminS]]

https://hg.mozilla.org/mozilla-central/rev/05176b3f8dcb

Comment 9

[Bogdan Tara[:bogdan_tara | bogdant]]

Backed out changeset 05176b3f8dcb (bug 1667336) for hazard failures on BytecodeEmitter.

Push with failures: https://treeherder.mozilla.org/#/jobs?repo=autoland&searchStr=hazard&tochange=00e795e5aeb16945e822e0e8dc33974326d3c014&selectedTaskRun=AifASqbSSwG1xCBlKgKnmw.0&fromchange=15495a0b869cb8bcf6486eee883be858e7935174

Backout link: https://hg.mozilla.org/integration/autoland/rev/da89153adb6f8b7b4052a787a6e0db8c281c363f

Failure log: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=317270763&repo=autoland&lineNumber=7265

Comment 10

[Sebastian Hengst [:aryx] (needinfo me if it's about an intermittent or backout)]

Backout merged:
https://hg.mozilla.org/mozilla-central/rev/da89153adb6f

Comment 11

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/5b1c2b34e4f5
Don't check atom marking when GC marking if the current thread holds the helper thread mutex r=sfink

Comment 12

[Dorel Luca [:dluca]]

https://hg.mozilla.org/mozilla-central/rev/5b1c2b34e4f5

Comment 13

[Jason Kratzer [:jkratzer]]

Bugmon Analysis:
Verified bug as fixed on rev mozilla-central 20201027044126-46a0e993f8bb.
Removing bugmon keyword as no further action possible.
Please review the bug and re-add the keyword for further analysis.