Sebastian Hengst [:aryx] (needinfo me if it's about an intermittent or backout) Reporter
	Description • 6 years ago

https://treeherder.mozilla.org/logviewer.html#?job_id=179186692&repo=try

First occurrence 2 days ago, only hit central-as-beta simulations and an unusual push from dao https://treeherder.mozilla.org/#/jobs?repo=try&revision=7958bfdf67172760389ca8bd2bafa78d364c5c53&filter-tier=1&filter-tier=2&filter-tier=3&filter-searchStr=tsan

task 2018-05-18T14:21:03.213Z] TEST-PASS | js/src/jit-test/tests/gc/bug-1144738.js | Success (code 3, args "--fuzzing-safe --thread-count=1 --ion-eager --ion-eager --ion-check-range-analysis --ion-extra-checks --no-sse3") [0.8 s]
[task 2018-05-18T14:21:03.213Z] {"action": "test_start", "pid": 3763, "source": "jittests", "test": "gc/bug-1144738.js", "thread": "main", "time": 1526653262.405937}
[task 2018-05-18T14:21:03.213Z] {"action": "test_end", "extra": {"jitflags": "--fuzzing-safe --thread-count=1 --ion-eager --ion-eager --ion-check-range-analysis --ion-extra-checks --no-sse3"}, "message": "Success", "pid": 3763, "source": "jittests", "status": "PASS", "test": "gc/bug-1144738.js", "thread": "main", "time": 1526653263.213106}
[task 2018-05-18T14:21:03.244Z] ==================
[task 2018-05-18T14:21:03.244Z] WARNING: ThreadSanitizer: data race (pid=115822)
[task 2018-05-18T14:21:03.245Z]   Read of size 4 at 0x7ffff46a42cc by main thread:
[task 2018-05-18T14:21:03.245Z]     #0 isForwarded /builds/worker/workspace/build/src/js/src/gc/RelocationOverlay.h:63:16 (js+0x112a1c9)
[task 2018-05-18T14:21:03.245Z]     #1 IsForwarded<js::LazyScript> /builds/worker/workspace/build/src/js/src/gc/Marking-inl.h:45 (js+0x112a1c9)
[task 2018-05-18T14:21:03.245Z]     #2 updateEdge<js::LazyScript> /builds/worker/workspace/build/src/js/src/gc/GC.cpp:2524 (js+0x112a1c9)
[task 2018-05-18T14:21:03.245Z]     #3 js::gc::MovingTracer::onLazyScriptEdge(js::LazyScript**) /builds/worker/workspace/build/src/js/src/gc/GC.cpp:2532 (js+0x112a1c9)
[task 2018-05-18T14:21:03.245Z]     #4 dispatchToOnEdge /builds/worker/workspace/build/src/obj-spider/dist/include/js/TracingAPI.h:251:53 (js+0x11b0f79)
[task 2018-05-18T14:21:03.245Z]     #5 js::LazyScript* DoCallback<js::LazyScript*>(JS::CallbackTracer*, js::LazyScript**, char const*) /builds/worker/workspace/build/src/js/src/gc/Tracer.cpp:48 (js+0x11b0f79)
[task 2018-05-18T14:21:03.245Z]     #6 void DispatchToTracer<js::LazyScript*>(JSTracer*, js::LazyScript**, char const*) /builds/worker/workspace/build/src/js/src/gc/Marking.cpp:691:5 (js+0x11695c1)
[task 2018-05-18T14:21:03.245Z]     #7 void js::TraceManuallyBarrieredEdge<js::LazyScript*>(JSTracer*, js::LazyScript**, char const*) /builds/worker/workspace/build/src/js/src/gc/Marking.cpp:474:5 (js+0x11696c5)
[task 2018-05-18T14:21:03.245Z]     #8 JSScript::traceChildren(JSTracer*) /builds/worker/workspace/build/src/js/src/vm/JSScript.cpp:3928:9 (js+0xd8b53c)
[task 2018-05-18T14:21:03.245Z]     #9 UpdateCellPointers<JSScript> /builds/worker/workspace/build/src/js/src/gc/GC.cpp:2592:11 (js+0x112b2d2)
[task 2018-05-18T14:21:03.245Z]     #10 UpdateArenaPointersTyped<JSScript> /builds/worker/workspace/build/src/js/src/gc/GC.cpp:2600 (js+0x112b2d2)
[task 2018-05-18T14:21:03.245Z]     #11 UpdateArenaPointers /builds/worker/workspace/build/src/js/src/gc/GC.cpp:2616 (js+0x112b2d2)
[task 2018-05-18T14:21:03.245Z]     #12 js::gc::UpdatePointersTask::updateArenas() /builds/worker/workspace/build/src/js/src/gc/GC.cpp:2738 (js+0x112b2d2)
[task 2018-05-18T14:21:03.245Z]     #13 run /builds/worker/workspace/build/src/js/src/gc/GC.cpp:2748:9 (js+0x11593db)
[task 2018-05-18T14:21:03.245Z]     #14 js::GCParallelTaskHelper<js::gc::UpdatePointersTask>::runTaskTyped(js::GCParallelTask*) /builds/worker/workspace/build/src/js/src/gc/GCParallelTask.h:150 (js+0x11593db)
[task 2018-05-18T14:21:03.245Z]     #15 runTask /builds/worker/workspace/build/src/js/src/gc/GCParallelTask.h:127:9 (js+0xd1080e)
[task 2018-05-18T14:21:03.245Z]     #16 js::GCParallelTask::runFromMainThread(JSRuntime*) /builds/worker/workspace/build/src/js/src/vm/HelperThreads.cpp:1570 (js+0xd1080e)
[task 2018-05-18T14:21:03.245Z]     #17 js::gc::GCRuntime::updateCellPointers(JS::Zone*, mozilla::EnumSet<js::gc::AllocKind>, unsigned long) /builds/worker/workspace/build/src/js/src/gc/GC.cpp:2824:13 (js+0x112c57c)
[task 2018-05-18T14:21:03.245Z]     #18 updateAllCellPointers /builds/worker/workspace/build/src/js/src/gc/GC.cpp:2894:5 (js+0x112ca9d)
[task 2018-05-18T14:21:03.245Z]     #19 js::gc::GCRuntime::updateZonePointersToRelocatedCells(JS::Zone*) /builds/worker/workspace/build/src/js/src/gc/GC.cpp:2933 (js+0x112ca9d)
[task 2018-05-18T14:21:03.245Z]     #20 js::gc::GCRuntime::compactPhase(JS::gcreason::Reason, js::SliceBudget&, js::gc::AutoTraceSession&) /builds/worker/workspace/build/src/js/src/gc/GC.cpp:6727:13 (js+0x1143a5d)
[task 2018-05-18T14:21:03.245Z]     #21 js::gc::GCRuntime::incrementalCollectSlice(js::SliceBudget&, JS::gcreason::Reason, js::gc::AutoTraceSession&) /builds/worker/workspace/build/src/js/src/gc/GC.cpp:7197:17 (js+0x1146026)
[task 2018-05-18T14:21:03.245Z]     #22 js::gc::GCRuntime::gcCycle(bool, js::SliceBudget&, JS::gcreason::Reason) /builds/worker/workspace/build/src/js/src/gc/GC.cpp:7478:5 (js+0x1147781)
[task 2018-05-18T14:21:03.245Z]     #23 js::gc::GCRuntime::collect(bool, js::SliceBudget, JS::gcreason::Reason) /builds/worker/workspace/build/src/js/src/gc/GC.cpp:7622:25 (js+0x1148d13)
[task 2018-05-18T14:21:03.245Z]     #24 gc /builds/worker/workspace/build/src/js/src/gc/GC.cpp:7692:5 (js+0x114d058)
[task 2018-05-18T14:21:03.245Z]     #25 JS::GCForReason(JSContext*, JSGCInvocationKind, JS::gcreason::Reason) /builds/worker/workspace/build/src/js/src/gc/GC.cpp:8531 (js+0x114d058)
[task 2018-05-18T14:21:03.245Z]     #26 GC(JSContext*, unsigned int, JS::Value*) /builds/worker/workspace/build/src/js/src/builtin/TestingFunctions.cpp:351:5 (js+0xa66ba0)
[task 2018-05-18T14:21:03.245Z]     #27 CallJSNative /builds/worker/workspace/build/src/js/src/vm/JSContext-inl.h:280:15 (js+0x5e9600)
[task 2018-05-18T14:21:03.245Z]     #28 js::InternalCallOrConstruct(JSContext*, JS::CallArgs const&, js::MaybeConstruct) /builds/worker/workspace/build/src/js/src/vm/Interpreter.cpp:467 (js+0x5e9600)
[task 2018-05-18T14:21:03.245Z]     #29 InternalCall(JSContext*, js::AnyInvokeArgs const&) /builds/worker/workspace/build/src/js/src/vm/Interpreter.cpp:516:12 (js+0x5e9b98)
[task 2018-05-18T14:21:03.245Z]     #30 js::CallFromStack(JSContext*, JS::CallArgs const&) /builds/worker/workspace/build/src/js/src/vm/Interpreter.cpp:522:12 (js+0x5e9abe)
[task 2018-05-18T14:21:03.245Z]     #31 js::jit::DoCallFallback(JSContext*, js::jit::BaselineFrame*, js::jit::ICCall_Fallback*, unsigned int, JS::Value*, JS::MutableHandle<JS::Value>) /builds/worker/workspace/build/src/js/src/jit/BaselineIC.cpp:2382:14 (js+0x6ce581)
[task 2018-05-18T14:21:03.245Z]     #32 <null> <null> (0x7fffb3d14e31)
[task 2018-05-18T14:21:03.245Z]     #33 js::RunScript(JSContext*, js::RunState&) /builds/worker/workspace/build/src/js/src/vm/Interpreter.cpp:402:34 (js+0x5d11be)
[task 2018-05-18T14:21:03.245Z]     #34 js::ExecuteKernel(JSContext*, JS::Handle<JSScript*>, JSObject&, JS::Value const&, js::AbstractFramePtr, JS::Value*) /builds/worker/workspace/build/src/js/src/vm/Interpreter.cpp:700:15 (js+0x5ea8ae)
[task 2018-05-18T14:21:03.245Z]     #35 js::Execute(JSContext*, JS::Handle<JSScript*>, JSObject&, JS::Value*) /builds/worker/workspace/build/src/js/src/vm/Interpreter.cpp:732:12 (js+0x5eaafd)
[task 2018-05-18T14:21:03.246Z]     #36 ExecuteScript(JSContext*, JS::Handle<JSObject*>, JS::Handle<JSScript*>, JS::Value*) /builds/worker/workspace/build/src/js/src/jsapi.cpp:4751:12 (js+0xbae306)
[task 2018-05-18T14:21:03.247Z]     #37 JS_ExecuteScript(JSContext*, JS::Handle<JSScript*>) /builds/worker/workspace/build/src/js/src/jsapi.cpp:4784:12 (js+0xbae3a9)
[task 2018-05-18T14:21:03.247Z]     #38 RunFile /builds/worker/workspace/build/src/js/src/shell/js.cpp:837:14 (js+0x4f023d)
[task 2018-05-18T14:21:03.247Z]     #39 Process(JSContext*, char const*, bool, FileKind) /builds/worker/workspace/build/src/js/src/shell/js.cpp:1307 (js+0x4f023d)
[task 2018-05-18T14:21:03.247Z]     #40 ProcessArgs /builds/worker/workspace/build/src/js/src/shell/js.cpp:8423:18 (js+0x4cd489)
[task 2018-05-18T14:21:03.247Z]     #41 Shell /builds/worker/workspace/build/src/js/src/shell/js.cpp:8851 (js+0x4cd489)
[task 2018-05-18T14:21:03.247Z]     #42 main /builds/worker/workspace/build/src/js/src/shell/js.cpp:9326 (js+0x4cd489)
[task 2018-05-18T14:21:03.248Z] 
[task 2018-05-18T14:21:03.248Z]   Previous write of size 8 at 0x7ffff46a42c8 by thread T3:
[task 2018-05-18T14:21:03.248Z]     #0 updateEdge<JSScript> /builds/worker/workspace/build/src/js/src/gc/GC.cpp:2525:17 (js+0x112a158)
[task 2018-05-18T14:21:03.248Z]     #1 js::gc::MovingTracer::onScriptEdge(JSScript**) /builds/worker/workspace/build/src/js/src/gc/GC.cpp:2531 (js+0x112a158)
[task 2018-05-18T14:21:03.248Z]     #2 dispatchToOnEdge /builds/worker/workspace/build/src/obj-spider/dist/include/js/TracingAPI.h:246:49 (js+0x11b11f9)
[task 2018-05-18T14:21:03.248Z]     #3 JSScript* DoCallback<JSScript*>(JS::CallbackTracer*, JSScript**, char const*) /builds/worker/workspace/build/src/js/src/gc/Tracer.cpp:48 (js+0x11b11f9)
[task 2018-05-18T14:21:03.249Z]     #4 DispatchToTracer<JSScript *> /builds/worker/workspace/build/src/js/src/gc/Marking.cpp:691:5 (js+0x11777f4)
[task 2018-05-18T14:21:03.249Z]     #5 TraceWeakEdge<JSScript *> /builds/worker/workspace/build/src/js/src/gc/Marking.cpp:491 (js+0x11777f4)
[task 2018-05-18T14:21:03.249Z]     #6 js::LazyScript::traceChildren(JSTracer*) /builds/worker/workspace/build/src/js/src/gc/Marking.cpp:1045 (js+0x11777f4)
[task 2018-05-18T14:21:03.249Z]     #7 UpdateCellPointers<js::LazyScript> /builds/worker/workspace/build/src/js/src/gc/GC.cpp:2592:11 (js+0x112b4b2)
[task 2018-05-18T14:21:03.249Z]     #8 UpdateArenaPointersTyped<js::LazyScript> /builds/worker/workspace/build/src/js/src/gc/GC.cpp:2600 (js+0x112b4b2)
[task 2018-05-18T14:21:03.250Z]     #9 UpdateArenaPointers /builds/worker/workspace/build/src/js/src/gc/GC.cpp:2616 (js+0x112b4b2)
[task 2018-05-18T14:21:03.250Z]     #10 js::gc::UpdatePointersTask::updateArenas() /builds/worker/workspace/build/src/js/src/gc/GC.cpp:2738 (js+0x112b4b2)
[task 2018-05-18T14:21:03.250Z]     #11 run /builds/worker/workspace/build/src/js/src/gc/GC.cpp:2748:9 (js+0x11593db)
[task 2018-05-18T14:21:03.250Z]     #12 js::GCParallelTaskHelper<js::gc::UpdatePointersTask>::runTaskTyped(js::GCParallelTask*) /builds/worker/workspace/build/src/js/src/gc/GCParallelTask.h:150 (js+0x11593db)
[task 2018-05-18T14:21:03.250Z]     #13 runTask /builds/worker/workspace/build/src/js/src/gc/GCParallelTask.h:127:9 (js+0xd10b8f)
[task 2018-05-18T14:21:03.250Z]     #14 runFromHelperThread /builds/worker/workspace/build/src/js/src/vm/HelperThreads.cpp:1586 (js+0xd10b8f)
[task 2018-05-18T14:21:03.250Z]     #15 js::HelperThread::handleGCParallelWorkload(js::AutoLockHelperThreadState&) /builds/worker/workspace/build/src/js/src/vm/HelperThreads.cpp:1612 (js+0xd10b8f)
[task 2018-05-18T14:21:03.250Z]     #16 js::HelperThread::threadLoop() /builds/worker/workspace/build/src/js/src/vm/HelperThreads.cpp:2385:9 (js+0xd12519)
[task 2018-05-18T14:21:03.250Z]     #17 js::HelperThread::ThreadMain(void*) /builds/worker/workspace/build/src/js/src/vm/HelperThreads.cpp:1869:38 (js+0xd0d481)
[task 2018-05-18T14:21:03.250Z]     #18 callMain<0> /builds/worker/workspace/build/src/js/src/threading/Thread.h:242:5 (js+0xd26dcb)
[task 2018-05-18T14:21:03.250Z]     #19 js::detail::ThreadTrampoline<void (&)(void*), js::HelperThread*>::Start(void*) /builds/worker/workspace/build/src/js/src/threading/Thread.h:235 (js+0xd26dcb)
[task 2018-05-18T14:21:03.250Z] 
[task 2018-05-18T14:21:03.250Z]   Thread T3 'JS Helper' (tid=115834, running) created by main thread at:
[task 2018-05-18T14:21:03.251Z]     #0 pthread_create /builds/worker/workspace/moz-toolchain/src/llvm/projects/compiler-rt/lib/tsan/rtl/tsan_interceptors.cc:889:3 (js+0x459353)
[task 2018-05-18T14:21:03.251Z]     #1 js::Thread::create(void* (*)(void*), void*) /builds/worker/workspace/build/src/js/src/threading/posix/Thread.cpp:115:7 (js+0xc10050)
[task 2018-05-18T14:21:03.251Z]     #2 init<void (&)(void *), js::HelperThread *> /builds/worker/workspace/build/src/js/src/threading/Thread.h:124:12 (js+0xd07f77)
[task 2018-05-18T14:21:03.251Z]     #3 js::GlobalHelperThreadState::ensureInitialized() /builds/worker/workspace/build/src/js/src/vm/HelperThreads.cpp:979 (js+0xd07f77)
[task 2018-05-18T14:21:03.251Z]     #4 js::EnsureHelperThreadsInitialized() /builds/worker/workspace/build/src/js/src/vm/HelperThreads.cpp:69:32 (js+0xd07cb2)
[task 2018-05-18T14:21:03.251Z]     #5 JSRuntime::init(JSContext*, unsigned int, unsigned int) /builds/worker/workspace/build/src/js/src/vm/Runtime.cpp:208:34 (js+0xddc3ad)
[task 2018-05-18T14:21:03.251Z]     #6 js::NewContext(unsigned int, unsigned int, JSRuntime*) /builds/worker/workspace/build/src/js/src/vm/JSContext.cpp:149:19 (js+0xd3154a)
[task 2018-05-18T14:21:03.251Z]     #7 JS_NewContext(unsigned int, unsigned int, JSRuntime*) /builds/worker/workspace/build/src/js/src/jsapi.cpp:472:12 (js+0xb95bd4)
[task 2018-05-18T14:21:03.251Z]     #8 main /builds/worker/workspace/build/src/js/src/shell/js.cpp:9247:21 (js+0x4ca4df)
[task 2018-05-18T14:21:03.251Z] 
[task 2018-05-18T14:21:03.252Z] SUMMARY: ThreadSanitizer: data race /builds/worker/workspace/build/src/js/src/gc/RelocationOverlay.h:63:16 in isForwarded
[task 2018-05-18T14:21:03.252Z] ==================
[task 2018-05-18T14:21:03.252Z] /builds/worker/workspace/build/src/js/src/jit-test/tests/gc/bug-1136597.js line 25 > eval:1:7 ReferenceError: g1 is not defined
[task 2018-05-18T14:21:03.252Z] Stack:
[task 2018-05-18T14:21:03.252Z]   @/builds/worker/workspace/build/src/js/src/jit-test/tests/gc/bug-1136597.js line 25 > eval:1:7
[task 2018-05-18T14:21:03.252Z]   @/builds/worker/workspace/build/src/js/src/jit-test/tests/gc/bug-1136597.js:25:1
[task 2018-05-18T14:21:03.252Z] ThreadSanitizer: reported 1 warnings
[task 2018-05-18T14:21:03.252Z] Exit code: 66
[task 2018-05-18T14:21:03.252Z] FAIL - gc/bug-1136597.js
[task 2018-05-18T14:21:03.252Z] TEST-UNEXPECTED-FAIL | js/src/jit-test/tests/gc/bug-1136597.js | ================== (code 66, args "--ion-eager --ion-check-range-analysis --ion-extra-checks --no-sse3") [2.1 s]

	Sebastian Hengst [:aryx] (needinfo me if it's about an intermittent or backout) Reporter
	Comment 1 • 6 years ago

This is a very frequent tsan failure. Please take a look at this.

	Steve Fink [:sfink] [:s:]
	Comment 2 • 6 years ago

Jon, this looks more up your alley. I may try to get this today, but I have other things in front of it.

From the error report, it seems like we have both the main thread and a helper thread running UpdatePointersTask::updateArenas at the same time on the same data.

	Jon Coppeard (:jonco) Assignee
	Comment 3 • 6 years ago

This happens while updating cells during compacting GC.

What happens is that a JSScript can ask IsForwarded() of its LazyScript while the LazyScript is having its cell pointers updated.  The LazyScript's JSScript pointer is in the part of the cell that we use for the relocation overlay, so if we update this pointer at the same time we get a race.  Note that the outcome of IsForwarded() would be false in both cases (the LazyScript itself is the relocated copy).

Anyway, we can just update JSScripts and LazyScripts in different phases so this possibility can't arise.

	Jon Coppeard (:jonco) Assignee
	Comment 4 • 6 years ago

I'm going to classify this as sec-moderate because I think this race is probably benign and I don't think this is exploitable.

	Jon Coppeard (:jonco) Assignee
	Comment 5 • 6 years ago

https://hg.mozilla.org/integration/mozilla-inbound/rev/6e430a8ad9cc8e2568a9f5f87bcb324a6db68916

	Ryan VanderMeulen [:RyanVM]
	Comment 6 • 6 years ago

https://hg.mozilla.org/mozilla-central/rev/6e430a8ad9cc

Is this something we should consider backporting or can it ride the trains? It grafts cleanly to Beta/ESR60.

	Jon Coppeard (:jonco) Assignee
	Comment 7 • 6 years ago

(In reply to Ryan VanderMeulen [:RyanVM] from comment #6)
> https://hg.mozilla.org/mozilla-central/rev/6e430a8ad9cc
> 
> Is this something we should consider backporting or can it ride the trains?
> It grafts cleanly to Beta/ESR60.

I think this is benign and can ride the trains.