Closed Bug 1774773 Opened 2 years ago Closed 2 years ago

Intermittent SUMMARY: ThreadSanitizer: data race /builds/worker/checkouts/gecko/tools/profiler/core/platform.cpp:2591:37 in StreamMarkerSchema

Categories

(Core :: Gecko Profiler, defect, P2)

defect

Tracking

()

RESOLVED FIXED
106 Branch
Tracking Status
firefox106 --- fixed

People

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

References

(Blocks 1 open bug)

Details

(Keywords: intermittent-failure)

Attachments

(1 file)

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


[task 2022-06-17T10:27:21.898Z] 10:27:21     INFO -  TEST-START | tools/profiler/tests/xpcshell/test_enterjit_osr.js
[task 2022-06-17T10:27:23.131Z] 10:27:23  WARNING -  TEST-UNEXPECTED-FAIL | tools/profiler/tests/xpcshell/test_enterjit_osr.js | xpcshell return code: -6
[task 2022-06-17T10:27:23.132Z] 10:27:23     INFO -  TEST-INFO took 1233ms
[task 2022-06-17T10:27:23.133Z] 10:27:23     INFO -  >>>>>>>
[task 2022-06-17T10:27:23.134Z] 10:27:23     INFO -  (xpcshell/head.js) | test MAIN run_test pending (1)
[task 2022-06-17T10:27:23.134Z] 10:27:23     INFO -  TEST-PASS | tools/profiler/tests/xpcshell/test_enterjit_osr.js | run_test - [run_test : 8] true == true
[task 2022-06-17T10:27:23.135Z] 10:27:23     INFO -  "loop: ms = 5"
[task 2022-06-17T10:27:23.135Z] 10:27:23     INFO -  PID 19137 | ==================
[task 2022-06-17T10:27:23.137Z] 10:27:23     INFO -  PID 19137 | WARNING: ThreadSanitizer: data race (pid=19137)
[task 2022-06-17T10:27:23.137Z] 10:27:23     INFO -  PID 19137 |   Read of size 8 at 0x561bfb8cd980 by main thread (mutexes: write M0):
[task 2022-06-17T10:27:23.138Z] 10:27:23     INFO -  PID 19137 |     #0 StreamMarkerSchema /builds/worker/checkouts/gecko/tools/profiler/core/platform.cpp:2591:37 (libxul.so+0x7eb1420) (BuildId: a3910d6fb0b2546905b9578b4ced7a4be4116dcf)
[task 2022-06-17T10:27:23.138Z] 10:27:23     INFO -  PID 19137 |     #1 StreamMetaJSCustomObject /builds/worker/checkouts/gecko/tools/profiler/core/platform.cpp:2739:3 (libxul.so+0x7eb1420)
[task 2022-06-17T10:27:23.139Z] 10:27:23     INFO -  PID 19137 |     #2 locked_profiler_stream_json_for_this_process(PSAutoLock const&, mozilla::baseprofiler::SpliceableJSONWriter&, double, PreRecordedMetaInformation const&, bool, ProfilerCodeAddressService*, mozilla::ProgressLogger) /builds/worker/checkouts/gecko/tools/profiler/core/platform.cpp:3140:5 (libxul.so+0x7eb1420)
[task 2022-06-17T10:27:23.140Z] 10:27:23     INFO -  PID 19137 |     #3 do_profiler_stream_json_for_this_process(mozilla::baseprofiler::SpliceableJSONWriter&, double, bool, ProfilerCodeAddressService*, mozilla::ProgressLogger) /builds/worker/checkouts/gecko/tools/profiler/core/platform.cpp:3318:3 (libxul.so+0x7eb01cb) (BuildId: a3910d6fb0b2546905b9578b4ced7a4be4116dcf)
[task 2022-06-17T10:27:23.140Z] 10:27:23     INFO -  PID 19137 |     #4 profiler_stream_json_for_this_process(mozilla::baseprofiler::SpliceableJSONWriter&, double, bool, ProfilerCodeAddressService*, mozilla::ProgressLogger) /builds/worker/checkouts/gecko/tools/profiler/core/platform.cpp:3335:10 (libxul.so+0x7eb583e) (BuildId: a3910d6fb0b2546905b9578b4ced7a4be4116dcf)
[task 2022-06-17T10:27:23.141Z] 10:27:23     INFO -  PID 19137 |     #5 WriteProfileToJSONWriter(mozilla::baseprofiler::SpliceableChunkedJSONWriter&, double, bool, ProfilerCodeAddressService*, mozilla::ProgressLogger) /builds/worker/checkouts/gecko/tools/profiler/core/platform.cpp:5213:10 (libxul.so+0x7ec4bdf) (BuildId: a3910d6fb0b2546905b9578b4ced7a4be4116dcf)
[task 2022-06-17T10:27:23.141Z] 10:27:23     INFO -  PID 19137 |     #6 profiler_get_profile(double, bool) /builds/worker/checkouts/gecko/tools/profiler/core/platform.cpp:5253:8 (libxul.so+0x7ec4807) (BuildId: a3910d6fb0b2546905b9578b4ced7a4be4116dcf)
[task 2022-06-17T10:27:23.142Z] 10:27:23     INFO -  PID 19137 |     #7 nsProfiler::GetProfileData(double, JSContext*, JS::MutableHandle<JS::Value>) /builds/worker/checkouts/gecko/tools/profiler/gecko/nsProfiler.cpp:332:40 (libxul.so+0x7f2663b) (BuildId: a3910d6fb0b2546905b9578b4ced7a4be4116dcf)
[task 2022-06-17T10:27:23.143Z] 10:27:23     INFO -  PID 19137 |     #8 NS_InvokeByIndex /builds/worker/checkouts/gecko/xpcom/reflect/xptcall/md/unix/xptcinvoke_asm_x86_64_unix.S:101 (libxul.so+0x1218785) (BuildId: a3910d6fb0b2546905b9578b4ced7a4be4116dcf)
[task 2022-06-17T10:27:23.150Z] 10:27:23     INFO -  PID 19137 |     #9 XPC_WN_CallMethod(JSContext*, unsigned int, JS::Value*) /builds/worker/checkouts/gecko/js/xpconnect/src/XPCWrappedNativeJSOps.cpp:963:10 (libxul.so+0x1fd7e06) (BuildId: a3910d6fb0b2546905b9578b4ced7a4be4116dcf)
[task 2022-06-17T10:27:23.151Z] 10:27:23     INFO -  PID 19137 |     #10 CallJSNative /builds/worker/checkouts/gecko/js/src/vm/Interpreter.cpp:421:13 (libxul.so+0x95baa3a) (BuildId: a3910d6fb0b2546905b9578b4ced7a4be4116dcf)
[task 2022-06-17T10:27:23.151Z] 10:27:23     INFO -  PID 19137 |     #11 js::InternalCallOrConstruct(JSContext*, JS::CallArgs const&, js::MaybeConstruct, js::CallReason) /builds/worker/checkouts/gecko/js/src/vm/Interpreter.cpp:508:12 (libxul.so+0x95baa3a)
[task 2022-06-17T10:27:23.151Z] 10:27:23     INFO -  PID 19137 |     #12 InternalCall /builds/worker/checkouts/gecko/js/src/vm/Interpreter.cpp:575:10 (libxul.so+0x95bb955) (BuildId: a3910d6fb0b2546905b9578b4ced7a4be4116dcf)
[task 2022-06-17T10:27:23.151Z] 10:27:23     INFO -  PID 19137 |     #13 js::CallFromStack(JSContext*, JS::CallArgs const&) /builds/worker/checkouts/gecko/js/src/vm/Interpreter.cpp:579:10 (libxul.so+0x95bb955)
[task 2022-06-17T10:27:23.151Z] 10:27:23     INFO -  PID 19137 |     #14 js::jit::DoCallFallback(JSContext*, js::jit::BaselineFrame*, js::jit::ICFallbackStub*, unsigned int, JS::Value*, JS::MutableHandle<JS::Value>) /builds/worker/checkouts/gecko/js/src/jit/BaselineIC.cpp:1582:10 (libxul.so+0x8ead80a) (BuildId: a3910d6fb0b2546905b9578b4ced7a4be4116dcf)
[task 2022-06-17T10:27:23.151Z] 10:27:23     INFO -  PID 19137 |     #15 <null> <null> (0x7fb509146e19)
[task 2022-06-17T10:27:23.151Z] 10:27:23     INFO -  PID 19137 |     #16 Interpret(JSContext*, js::RunState&) /builds/worker/checkouts/gecko/js/src/vm/Interpreter.cpp:2194:17 (libxul.so+0x95a457e) (BuildId: a3910d6fb0b2546905b9578b4ced7a4be4116dcf)
[task 2022-06-17T10:27:23.152Z] 10:27:23     INFO -  PID 19137 |     #17 js::RunScript(JSContext*, js::RunState&) /builds/worker/checkouts/gecko/js/src/vm/Interpreter.cpp:390:13 (libxul.so+0x95a35d7) (BuildId: a3910d6fb0b2546905b9578b4ced7a4be4116dcf)
[task 2022-06-17T10:27:23.152Z] 10:27:23     INFO -  PID 19137 |     #18 js::InternalCallOrConstruct(JSContext*, JS::CallArgs const&, js::MaybeConstruct, js::CallReason) /builds/worker/checkouts/gecko/js/src/vm/Interpreter.cpp:540:13 (libxul.so+0x95babc1) (BuildId: a3910d6fb0b2546905b9578b4ced7a4be4116dcf)
[task 2022-06-17T10:27:23.152Z] 10:27:23     INFO -  PID 19137 |     #19 InternalCall /builds/worker/checkouts/gecko/js/src/vm/Interpreter.cpp:575:10 (libxul.so+0x95bb955) (BuildId: a3910d6fb0b2546905b9578b4ced7a4be4116dcf)
[task 2022-06-17T10:27:23.152Z] 10:27:23     INFO -  PID 19137 |     #20 js::CallFromStack(JSContext*, JS::CallArgs const&) /builds/worker/checkouts/gecko/js/src/vm/Interpreter.cpp:579:10 (libxul.so+0x95bb955)
[task 2022-06-17T10:27:23.152Z] 10:27:23     INFO -  PID 19137 |     #21 js::jit::DoCallFallback(JSContext*, js::jit::BaselineFrame*, js::jit::ICFallbackStub*, unsigned int, JS::Value*, JS::MutableHandle<JS::Value>) /builds/worker/checkouts/gecko/js/src/jit/BaselineIC.cpp:1582:10 (libxul.so+0x8ead80a) (BuildId: a3910d6fb0b2546905b9578b4ced7a4be4116dcf)
[task 2022-06-17T10:27:23.152Z] 10:27:23     INFO -  PID 19137 |     #22 <null> <null> (0x7fb509146e19)
[task 2022-06-17T10:27:23.153Z] 10:27:23     INFO -  PID 19137 |     #23 Interpret(JSContext*, js::RunState&) /builds/worker/checkouts/gecko/js/src/vm/Interpreter.cpp:2194:17 (libxul.so+0x95a457e) (BuildId: a3910d6fb0b2546905b9578b4ced7a4be4116dcf)
[task 2022-06-17T10:27:23.153Z] 10:27:23     INFO -  PID 19137 |     #24 js::RunScript(JSContext*, js::RunState&) /builds/worker/checkouts/gecko/js/src/vm/Interpreter.cpp:390:13 (libxul.so+0x95a35d7) (BuildId: a3910d6fb0b2546905b9578b4ced7a4be4116dcf)
[task 2022-06-17T10:27:23.153Z] 10:27:23     INFO -  PID 19137 |     #25 js::ExecuteKernel(JSContext*, JS::Handle<JSScript*>, JS::Handle<JSObject*>, js::AbstractFramePtr, JS::MutableHandle<JS::Value>) /builds/worker/checkouts/gecko/js/src/vm/Interpreter.cpp:782:13 (libxul.so+0x95bcf32) (BuildId: a3910d6fb0b2546905b9578b4ced7a4be4116dcf)
[task 2022-06-17T10:27:23.153Z] 10:27:23     INFO -  PID 19137 |     #26 js::Execute(JSContext*, JS::Handle<JSScript*>, JS::Handle<JSObject*>, JS::MutableHandle<JS::Value>) /builds/worker/checkouts/gecko/js/src/vm/Interpreter.cpp:814:10 (libxul.so+0x95bd0f9) (BuildId: a3910d6fb0b2546905b9578b4ced7a4be4116dcf)
[task 2022-06-17T10:27:23.155Z] 10:27:23     INFO -  PID 19137 |     #27 EvaluateSourceBuffer<mozilla::Utf8Unit> /builds/worker/checkouts/gecko/js/src/vm/CompilationAndEvaluation.cpp:571:10 (libxul.so+0x875909e) (BuildId: a3910d6fb0b2546905b9578b4ced7a4be4116dcf)
[task 2022-06-17T10:27:23.155Z] 10:27:23     INFO -  PID 19137 |     #28 JS::Evaluate(JSContext*, JS::ReadOnlyCompileOptions const&, JS::SourceText<mozilla::Utf8Unit>&, JS::MutableHandle<JS::Value>) /builds/worker/checkouts/gecko/js/src/vm/CompilationAndEvaluation.cpp:579:10 (libxul.so+0x875909e)
[task 2022-06-17T10:27:23.155Z] 10:27:23     INFO -  PID 19137 |     #29 ProcessArgs(mozilla::dom::AutoJSAPI&, char**, int, XPCShellDirProvider*) /builds/worker/checkouts/gecko/js/xpconnect/src/XPCShellImpl.cpp:983:11 (libxul.so+0x1fc3ab4) (BuildId: a3910d6fb0b2546905b9578b4ced7a4be4116dcf)
[task 2022-06-17T10:27:23.156Z] 10:27:23     INFO -  PID 19137 |     #30 XRE_XPCShellMain(int, char**, char**, XREShellData const*) /builds/worker/checkouts/gecko/js/xpconnect/src/XPCShellImpl.cpp:1395:16 (libxul.so+0x1fc231b) (BuildId: a3910d6fb0b2546905b9578b4ced7a4be4116dcf)
[task 2022-06-17T10:27:23.157Z] 10:27:23     INFO -  PID 19137 |     #31 mozilla::BootstrapImpl::XRE_XPCShellMain(int, char**, char**, XREShellData const*) /builds/worker/checkouts/gecko/toolkit/xre/Bootstrap.cpp:54:12 (libxul.so+0x84ed31e) (BuildId: a3910d6fb0b2546905b9578b4ced7a4be4116dcf)
[task 2022-06-17T10:27:23.157Z] 10:27:23     INFO -  PID 19137 |     #32 main /builds/worker/checkouts/gecko/js/xpconnect/shell/xpcshell.cpp:82:27 (xpcshell+0xdea8d) (BuildId: bfd0f8d9aad6e6da8a23c6a8dcb6d65cc4b56a06)
[task 2022-06-17T10:27:23.158Z] 10:27:23     INFO -  PID 19137 |   Previous write of size 8 at 0x561bfb8cd980 by thread T4:
[task 2022-06-17T10:27:23.159Z] 10:27:23     INFO -  PID 19137 |     #0 mozilla::base_profiler_markers_detail::Streaming::TagForMarkerTypeFunctions(void (*)(mozilla::ProfileBufferEntryReader&, mozilla::baseprofiler::SpliceableJSONWriter&), mozilla::Span<char const, 18446744073709551615ul> (*)(), mozilla::MarkerSchema (*)()) /builds/worker/checkouts/gecko/mozglue/baseprofiler/core/ProfilerMarkers.cpp:57:39 (xpcshell+0xec091) (BuildId: bfd0f8d9aad6e6da8a23c6a8dcb6d65cc4b56a06)
[task 2022-06-17T10:27:23.160Z] 10:27:23     INFO -  PID 19137 |     #1 mozilla::ProfileBufferBlockIndex mozilla::base_profiler_markers_detail::MarkerTypeSerialization<mozilla::baseprofiler::markers::TextMarker>::Serialize<nsTAutoStringN<char, 64ul> >(mozilla::ProfileChunkedBuffer&, mozilla::ProfilerStringView<char> const&, mozilla::MarkerCategory const&, mozilla::MarkerOptions&&, nsTAutoStringN<char, 64ul> const&) /builds/worker/workspace/obj-build/dist/include/mozilla/BaseProfilerMarkersDetail.h:146:9 (libxul.so+0x11c9696) (BuildId: a3910d6fb0b2546905b9578b4ced7a4be4116dcf)
[task 2022-06-17T10:27:23.161Z] 10:27:23     INFO -  PID 19137 |     #2 mozilla::ProfileBufferBlockIndex mozilla::base_profiler_markers_detail::AddMarkerToBuffer<mozilla::baseprofiler::markers::TextMarker, nsTAutoStringN<char, 64ul> >(mozilla::ProfileChunkedBuffer&, mozilla::ProfilerStringView<char> const&, mozilla::MarkerCategory const&, mozilla::MarkerOptions&&, bool (*)(mozilla::ProfileChunkedBuffer&, mozilla::StackCaptureOptions), nsTAutoStringN<char, 64ul> const&) /builds/worker/workspace/obj-build/dist/include/mozilla/BaseProfilerMarkersDetail.h (libxul.so+0x11c9266) (BuildId: a3910d6fb0b2546905b9578b4ced7a4be4116dcf)
[task 2022-06-17T10:27:23.162Z] 10:27:23     INFO -  PID 19137 |     #3 mozilla::ProfileBufferBlockIndex AddMarkerToBuffer<mozilla::baseprofiler::markers::TextMarker, nsTAutoStringN<char, 64ul> >(mozilla::ProfileChunkedBuffer&, mozilla::ProfilerStringView<char> const&, mozilla::MarkerCategory const&, mozilla::MarkerOptions&&, mozilla::baseprofiler::markers::TextMarker, nsTAutoStringN<char, 64ul> const&) /builds/worker/workspace/obj-build/dist/include/mozilla/ProfilerMarkers.h:107:10 (libxul.so+0x11c8fb6) (BuildId: a3910d6fb0b2546905b9578b4ced7a4be4116dcf)
[task 2022-06-17T10:27:23.163Z] 10:27:23     INFO -  PID 19137 |     #4 mozilla::ProfileBufferBlockIndex profiler_add_marker<mozilla::baseprofiler::markers::TextMarker, nsTAutoStringN<char, 64ul> >(mozilla::ProfilerStringView<char> const&, mozilla::MarkerCategory const&, mozilla::MarkerOptions&&, mozilla::baseprofiler::markers::TextMarker, nsTAutoStringN<char, 64ul> const&) /builds/worker/workspace/obj-build/dist/include/mozilla/ProfilerMarkers.h:154:10 (libxul.so+0x11c8d29) (BuildId: a3910d6fb0b2546905b9578b4ced7a4be4116dcf)
[task 2022-06-17T10:27:23.163Z] 10:27:23     INFO -  PID 19137 |     #5 mozilla::AutoProfileRunnable::~AutoProfileRunnable() /builds/worker/workspace/obj-build/dist/include/mozilla/ProfilerRunnable.h:51:5 (libxul.so+0x11bdf49) (BuildId: a3910d6fb0b2546905b9578b4ced7a4be4116dcf)
[task 2022-06-17T10:27:23.164Z] 10:27:23     INFO -  PID 19137 |     #6 nsThread::ProcessNextEvent(bool, bool*) /builds/worker/checkouts/gecko/xpcom/threads/nsThread.cpp:1200:7 (libxul.so+0x11e4c30) (BuildId: a3910d6fb0b2546905b9578b4ced7a4be4116dcf)
[task 2022-06-17T10:27:23.164Z] 10:27:23     INFO -  PID 19137 |     #7 NS_ProcessNextEvent(nsIThread*, bool) /builds/worker/checkouts/gecko/xpcom/threads/nsThreadUtils.cpp:465:10 (libxul.so+0x11eb0f5) (BuildId: a3910d6fb0b2546905b9578b4ced7a4be4116dcf)
[task 2022-06-17T10:27:23.165Z] 10:27:23     INFO -  PID 19137 |     #8 mozilla::net::nsSocketTransportService::Run() /builds/worker/checkouts/gecko/netwerk/base/nsSocketTransportService2.cpp:1220:11 (libxul.so+0x13fb8a7) (BuildId: a3910d6fb0b2546905b9578b4ced7a4be4116dcf)
[task 2022-06-17T10:27:23.166Z] 10:27:23     INFO -  PID 19137 |     #9 non-virtual thunk to mozilla::net::nsSocketTransportService::Run() /builds/worker/checkouts/gecko/netwerk/base/nsSocketTransportService2.cpp (libxul.so+0x13fcd09) (BuildId: a3910d6fb0b2546905b9578b4ced7a4be4116dcf)
[task 2022-06-17T10:27:23.166Z] 10:27:23     INFO -  PID 19137 |     #10 nsThread::ProcessNextEvent(bool, bool*) /builds/worker/checkouts/gecko/xpcom/threads/nsThread.cpp:1199:16 (libxul.so+0x11e4c28) (BuildId: a3910d6fb0b2546905b9578b4ced7a4be4116dcf)
[task 2022-06-17T10:27:23.167Z] 10:27:23     INFO -  PID 19137 |     #11 NS_ProcessNextEvent(nsIThread*, bool) /builds/worker/checkouts/gecko/xpcom/threads/nsThreadUtils.cpp:465:10 (libxul.so+0x11eb0f5) (BuildId: a3910d6fb0b2546905b9578b4ced7a4be4116dcf)
[task 2022-06-17T10:27:23.168Z] 10:27:23     INFO -  PID 19137 |     #12 mozilla::ipc::MessagePumpForNonMainThreads::Run(base::MessagePump::Delegate*) /builds/worker/checkouts/gecko/ipc/glue/MessagePump.cpp:300:20 (libxul.so+0x1e46e4e) (BuildId: a3910d6fb0b2546905b9578b4ced7a4be4116dcf)
[task 2022-06-17T10:27:23.168Z] 10:27:23     INFO -  PID 19137 |     #13 RunInternal /builds/worker/checkouts/gecko/ipc/chromium/src/base/message_loop.cc:380:10 (libxul.so+0x1d65bdc) (BuildId: a3910d6fb0b2546905b9578b4ced7a4be4116dcf)
[task 2022-06-17T10:27:23.169Z] 10:27:23     INFO -  PID 19137 |     #14 RunHandler /builds/worker/checkouts/gecko/ipc/chromium/src/base/message_loop.cc:373:3 (libxul.so+0x1d65bdc)
[task 2022-06-17T10:27:23.169Z] 10:27:23     INFO -  PID 19137 |     #15 MessageLoop::Run() /builds/worker/checkouts/gecko/ipc/chromium/src/base/message_loop.cc:355:3 (libxul.so+0x1d65bdc)
[task 2022-06-17T10:27:23.170Z] 10:27:23     INFO -  PID 19137 |     #16 nsThread::ThreadFunc(void*) /builds/worker/checkouts/gecko/xpcom/threads/nsThread.cpp:384:10 (libxul.so+0x11dffe6) (BuildId: a3910d6fb0b2546905b9578b4ced7a4be4116dcf)
[task 2022-06-17T10:27:23.170Z] 10:27:23     INFO -  PID 19137 |     #17 _pt_root /builds/worker/checkouts/gecko/nsprpub/pr/src/pthreads/ptthread.c:201:5 (libnspr4.so+0x4615d) (BuildId: fb895833819c7e18063b759e51039980dd7a34c1)
[task 2022-06-17T10:27:23.171Z] 10:27:23     INFO -  PID 19137 |   Location is global 'mozilla::base_profiler_markers_detail::sMarkerTypeFunctions1Based' of size 6000 at 0x561bfb8cd8d0 (xpcshell+0x15fd980)
[task 2022-06-17T10:27:23.171Z] 10:27:23     INFO -  PID 19137 |   Mutex M0 (0x7fb5a7bedd10) created at:
[task 2022-06-17T10:27:23.172Z] 10:27:23     INFO -  PID 19137 |     #0 pthread_mutex_init /builds/worker/fetches/llvm-project/compiler-rt/lib/tsan/rtl/tsan_interceptors_posix.cpp:1316:3 (xpcshell+0x5f78f) (BuildId: bfd0f8d9aad6e6da8a23c6a8dcb6d65cc4b56a06)
[task 2022-06-17T10:27:23.173Z] 10:27:23     INFO -  PID 19137 |     #1 mozilla::detail::MutexImpl::MutexImpl() /builds/worker/checkouts/gecko/mozglue/misc/Mutex_posix.cpp:78:3 (xpcshell+0x1441c2) (BuildId: bfd0f8d9aad6e6da8a23c6a8dcb6d65cc4b56a06)
[task 2022-06-17T10:27:23.173Z] 10:27:23     INFO -  PID 19137 |     #2 BaseProfilerMutex /builds/worker/workspace/obj-build/dist/include/mozilla/BaseProfilerDetail.h:29:9 (libxul.so+0xbef191) (BuildId: a3910d6fb0b2546905b9578b4ced7a4be4116dcf)
[task 2022-06-17T10:27:23.174Z] 10:27:23     INFO -  PID 19137 |     #3 __cxx_global_var_init.68 /builds/worker/checkouts/gecko/tools/profiler/core/platform.cpp:404:17 (libxul.so+0xbef191)
[task 2022-06-17T10:27:23.174Z] 10:27:23     INFO -  PID 19137 |     #4 _GLOBAL__sub_I_Unified_cpp_tools_profiler0.cpp /builds/worker/workspace/obj-build/tools/profiler/Unified_cpp_tools_profiler0.cpp (libxul.so+0xbef191)
[task 2022-06-17T10:27:23.175Z] 10:27:23     INFO -  PID 19137 |     #5 <null> <null> (ld-linux-x86-64.so.2+0x10782) (BuildId: 822d3943c4bb51a173776d69a167a71a31522761)
[task 2022-06-17T10:27:23.175Z] 10:27:23     INFO -  PID 19137 |   Thread T4 'Socket Thread' (tid=19142, running) created by main thread at:
[task 2022-06-17T10:27:23.176Z] 10:27:23     INFO -  PID 19137 |     #0 pthread_create /builds/worker/fetches/llvm-project/compiler-rt/lib/tsan/rtl/tsan_interceptors_posix.cpp:1022:3 (xpcshell+0x5df8d) (BuildId: bfd0f8d9aad6e6da8a23c6a8dcb6d65cc4b56a06)
[task 2022-06-17T10:27:23.177Z] 10:27:23     INFO -  PID 19137 |     #1 _PR_CreateThread /builds/worker/checkouts/gecko/nsprpub/pr/src/pthreads/ptthread.c:458:14 (libnspr4.so+0x3d1b5) (BuildId: fb895833819c7e18063b759e51039980dd7a34c1)
[task 2022-06-17T10:27:23.177Z] 10:27:23     INFO -  PID 19137 |     #2 PR_CreateThread /builds/worker/checkouts/gecko/nsprpub/pr/src/pthreads/ptthread.c:533:12 (libnspr4.so+0x322a5) (BuildId: fb895833819c7e18063b759e51039980dd7a34c1)
[task 2022-06-17T10:27:23.178Z] 10:27:23     INFO -  PID 19137 |     #3 nsThread::Init(nsTSubstring<char> const&) /builds/worker/checkouts/gecko/xpcom/threads/nsThread.cpp:618:18 (libxul.so+0x11e1b65) (BuildId: a3910d6fb0b2546905b9578b4ced7a4be4116dcf)
[task 2022-06-17T10:27:23.178Z] 10:27:23     INFO -  PID 19137 |     #4 nsThreadManager::NewNamedThread(nsTSubstring<char> const&, unsigned int, nsIThread**) /builds/worker/checkouts/gecko/xpcom/threads/nsThreadManager.cpp:534:12 (libxul.so+0x11ea004) (BuildId: a3910d6fb0b2546905b9578b4ced7a4be4116dcf)
[task 2022-06-17T10:27:23.179Z] 10:27:23     INFO -  PID 19137 |     #5 NS_NewNamedThread(nsTSubstring<char> const&, nsIThread**, already_AddRefed<nsIRunnable>, unsigned int) /builds/worker/checkouts/gecko/xpcom/threads/nsThreadUtils.cpp:161:57 (libxul.so+0x11f2214) (BuildId: a3910d6fb0b2546905b9578b4ced7a4be4116dcf)
[task 2022-06-17T10:27:23.180Z] 10:27:23     INFO -  PID 19137 |     #6 NS_NewNamedThread<14UL> /builds/worker/workspace/obj-build/dist/include/nsThreadUtils.h:85:10 (libxul.so+0x13f9f4e) (BuildId: a3910d6fb0b2546905b9578b4ced7a4be4116dcf)
[task 2022-06-17T10:27:23.180Z] 10:27:23     INFO -  PID 19137 |     #7 mozilla::net::nsSocketTransportService::Init() /builds/worker/checkouts/gecko/netwerk/base/nsSocketTransportService2.cpp:776:9 (libxul.so+0x13f9f4e)
[task 2022-06-17T10:27:23.181Z] 10:27:23     INFO -  PID 19137 |     #8 mozilla::xpcom::CreateInstanceImpl(mozilla::xpcom::ModuleID, nsID const&, void**) /builds/worker/workspace/obj-build/xpcom/components/StaticComponents.cpp:9354:7 (libxul.so+0x11a1d0d) (BuildId: a3910d6fb0b2546905b9578b4ced7a4be4116dcf)
[task 2022-06-17T10:27:23.182Z] 10:27:23     INFO -  PID 19137 |     #9 mozilla::xpcom::StaticModule::CreateInstance(nsID const&, void**) const /builds/worker/workspace/obj-build/xpcom/components/StaticComponents.cpp:12073:10 (libxul.so+0x119d427) (BuildId: a3910d6fb0b2546905b9578b4ced7a4be4116dcf)
[task 2022-06-17T10:27:23.182Z] 10:27:23     INFO -  PID 19137 |     #10 CreateInstance /builds/worker/checkouts/gecko/xpcom/components/nsComponentManager.cpp:185:46 (libxul.so+0x11b4714) (BuildId: a3910d6fb0b2546905b9578b4ced7a4be4116dcf)
[task 2022-06-17T10:27:23.183Z] 10:27:23     INFO -  PID 19137 |     #11 nsComponentManagerImpl::GetServiceLocked(mozilla::Maybe<mozilla::detail::BaseMonitorAutoLock<mozilla::Monitor> >&, (anonymous namespace)::EntryWrapper&, nsID const&, void**) /builds/worker/checkouts/gecko/xpcom/components/nsComponentManager.cpp:1283:17 (libxul.so+0x11b4714)
[task 2022-06-17T10:27:23.184Z] 10:27:23     INFO -  PID 19137 |     #12 nsComponentManagerImpl::GetServiceByContractID(char const*, nsID const&, void**) /builds/worker/checkouts/gecko/xpcom/components/nsComponentManager.cpp:1472:10 (libxul.so+0x11b541f) (BuildId: a3910d6fb0b2546905b9578b4ced7a4be4116dcf)
[task 2022-06-17T10:27:23.184Z] 10:27:23     INFO -  PID 19137 |     #13 CallGetService /builds/worker/checkouts/gecko/xpcom/components/nsComponentManagerUtils.cpp:61:43 (libxul.so+0x11b8a6d) (BuildId: a3910d6fb0b2546905b9578b4ced7a4be4116dcf)
[task 2022-06-17T10:27:23.185Z] 10:27:23     INFO -  PID 19137 |     #14 nsGetServiceByContractIDWithError::operator()(nsID const&, void**) const /builds/worker/checkouts/gecko/xpcom/components/nsComponentManagerUtils.cpp:250:21 (libxul.so+0x11b8a6d)
[task 2022-06-17T10:27:23.186Z] 10:27:23     INFO -  PID 19137 |     #15 nsCOMPtr_base::assign_from_gs_contractid_with_error(nsGetServiceByContractIDWithError const&, nsID const&) /builds/worker/checkouts/gecko/xpcom/base/nsCOMPtr.cpp:91:7 (libxul.so+0x10e2927) (BuildId: a3910d6fb0b2546905b9578b4ced7a4be4116dcf)
[task 2022-06-17T10:27:23.186Z] 10:27:23     INFO -  PID 19137 |     #16 operator= /builds/worker/workspace/obj-build/dist/include/nsCOMPtr.h:774:5 (libxul.so+0x139dea1) (BuildId: a3910d6fb0b2546905b9578b4ced7a4be4116dcf)
[task 2022-06-17T10:27:23.187Z] 10:27:23     INFO -  PID 19137 |     #17 InitializeSocketTransportService /builds/worker/checkouts/gecko/netwerk/base/nsIOService.cpp:437:29 (libxul.so+0x139dea1)
[task 2022-06-17T10:27:23.188Z] 10:27:23     INFO -  PID 19137 |     #18 mozilla::net::nsIOService::SetOfflineInternal(bool, bool) /builds/worker/checkouts/gecko/netwerk/base/nsIOService.cpp:1338:7 (libxul.so+0x139dea1)
[task 2022-06-17T10:27:23.188Z] 10:27:23     INFO -  PID 19137 |     #19 SetOffline /builds/worker/checkouts/gecko/netwerk/base/nsIOService.cpp:1277:48 (libxul.so+0x1396c16) (BuildId: a3910d6fb0b2546905b9578b4ced7a4be4116dcf)
[task 2022-06-17T10:27:23.189Z] 10:27:23     INFO -  PID 19137 |     #20 mozilla::net::nsIOService::Init() /builds/worker/checkouts/gecko/netwerk/base/nsIOService.cpp:316:3 (libxul.so+0x1396c16)
[task 2022-06-17T10:27:23.189Z] 10:27:23     INFO -  PID 19137 |     #21 mozilla::net::nsIOService::GetInstance() /builds/worker/checkouts/gecko/netwerk/base/nsIOService.cpp:494:9 (libxul.so+0x13985a1) (BuildId: a3910d6fb0b2546905b9578b4ced7a4be4116dcf)
[task 2022-06-17T10:27:23.190Z] 10:27:23     INFO -  PID 19137 |     #22 mozilla::xpcom::CreateInstanceImpl(mozilla::xpcom::ModuleID, nsID const&, void**) /builds/worker/workspace/obj-build/xpcom/components/StaticComponents.cpp:10202:48 (libxul.so+0x11a4f67) (BuildId: a3910d6fb0b2546905b9578b4ced7a4be4116dcf)
[task 2022-06-17T10:27:23.191Z] 10:27:23     INFO -  PID 19137 |     #23 mozilla::xpcom::StaticModule::CreateInstance(nsID const&, void**) const /builds/worker/workspace/obj-build/xpcom/components/StaticComponents.cpp:12073:10 (libxul.so+0x119d427) (BuildId: a3910d6fb0b2546905b9578b4ced7a4be4116dcf)
[task 2022-06-17T10:27:23.192Z] 10:27:23     INFO -  PID 19137 |     #24 CreateInstance /builds/worker/checkouts/gecko/xpcom/components/nsComponentManager.cpp:185:46 (libxul.so+0x11b4714) (BuildId: a3910d6fb0b2546905b9578b4ced7a4be4116dcf)
[task 2022-06-17T10:27:23.193Z] 10:27:23     INFO -  PID 19137 |     #25 nsComponentManagerImpl::GetServiceLocked(mozilla::Maybe<mozilla::detail::BaseMonitorAutoLock<mozilla::Monitor> >&, (anonymous namespace)::EntryWrapper&, nsID const&, void**) /builds/worker/checkouts/gecko/xpcom/components/nsComponentManager.cpp:1283:17 (libxul.so+0x11b4714)
[task 2022-06-17T10:27:23.193Z] 10:27:23     INFO -  PID 19137 |     #26 nsComponentManagerImpl::GetServiceByContractID(char const*, nsID const&, void**) /builds/worker/checkouts/gecko/xpcom/components/nsComponentManager.cpp:1472:10 (libxul.so+0x11b541f) (BuildId: a3910d6fb0b2546905b9578b4ced7a4be4116dcf)
[task 2022-06-17T10:27:23.194Z] 10:27:23     INFO -  PID 19137 |     #27 CallGetService(char const*, nsID const&, void**) /builds/worker/checkouts/gecko/xpcom/components/nsComponentManagerUtils.cpp:61:43 (libxul.so+0x11b83cd) (BuildId: a3910d6fb0b2546905b9578b4ced7a4be4116dcf)
[task 2022-06-17T10:27:23.195Z] 10:27:23     INFO -  PID 19137 |     #28 CallGetService<nsIIOService> /builds/worker/workspace/obj-build/dist/include/nsServiceManagerUtils.h:52:10 (libxul.so+0x213a11a) (BuildId: a3910d6fb0b2546905b9578b4ced7a4be4116dcf)
[task 2022-06-17T10:27:23.195Z] 10:27:23     INFO -  PID 19137 |     #29 nsScriptSecurityManager::Init() /builds/worker/checkouts/gecko/caps/nsScriptSecurityManager.cpp:1500:17 (libxul.so+0x213a11a)
[task 2022-06-17T10:27:23.196Z] 10:27:23     INFO -  PID 19137 |     #30 nsScriptSecurityManager::InitStatics() /builds/worker/checkouts/gecko/caps/nsScriptSecurityManager.cpp:1561:28 (libxul.so+0x213a701) (BuildId: a3910d6fb0b2546905b9578b4ced7a4be4116dcf)
[task 2022-06-17T10:27:23.197Z] 10:27:23     INFO -  PID 19137 |     #31 nsXPConnect::InitStatics() /builds/worker/checkouts/gecko/js/xpconnect/src/nsXPConnect.cpp:158:3 (libxul.so+0x1fe19e3) (BuildId: a3910d6fb0b2546905b9578b4ced7a4be4116dcf)
[task 2022-06-17T10:27:23.198Z] 10:27:23     INFO -  PID 19137 |     #32 xpcModuleCtor() /builds/worker/checkouts/gecko/js/xpconnect/src/XPCModule.cpp:11:3 (libxul.so+0x1fae9d2) (BuildId: a3910d6fb0b2546905b9578b4ced7a4be4116dcf)
[task 2022-06-17T10:27:23.198Z] 10:27:23     INFO -  PID 19137 |     #33 nsLayoutModuleInitialize() /builds/worker/checkouts/gecko/layout/build/nsLayoutModule.cpp:100:7 (libxul.so+0x634c0cb) (BuildId: a3910d6fb0b2546905b9578b4ced7a4be4116dcf)
[task 2022-06-17T10:27:23.199Z] 10:27:23     INFO -  PID 19137 |     #34 nsComponentManagerImpl::Init() /builds/worker/checkouts/gecko/xpcom/components/nsComponentManager.cpp:415:5 (libxul.so+0x11b0264) (BuildId: a3910d6fb0b2546905b9578b4ced7a4be4116dcf)
[task 2022-06-17T10:27:23.200Z] 10:27:23     INFO -  PID 19137 |     #35 NS_InitXPCOM /builds/worker/checkouts/gecko/xpcom/build/XPCOMInit.cpp:456:51 (libxul.so+0x1229e23) (BuildId: a3910d6fb0b2546905b9578b4ced7a4be4116dcf)
[task 2022-06-17T10:27:23.200Z] 10:27:23     INFO -  PID 19137 |     #36 XRE_XPCShellMain(int, char**, char**, XREShellData const*) /builds/worker/checkouts/gecko/js/xpconnect/src/XPCShellImpl.cpp:1232:10 (libxul.so+0x1fc1cf2) (BuildId: a3910d6fb0b2546905b9578b4ced7a4be4116dcf)
[task 2022-06-17T10:27:23.201Z] 10:27:23     INFO -  PID 19137 |     #37 mozilla::BootstrapImpl::XRE_XPCShellMain(int, char**, char**, XREShellData const*) /builds/worker/checkouts/gecko/toolkit/xre/Bootstrap.cpp:54:12 (libxul.so+0x84ed31e) (BuildId: a3910d6fb0b2546905b9578b4ced7a4be4116dcf)
[task 2022-06-17T10:27:23.202Z] 10:27:23     INFO -  PID 19137 |     #38 main /builds/worker/checkouts/gecko/js/xpconnect/shell/xpcshell.cpp:82:27 (xpcshell+0xdea8d) (BuildId: bfd0f8d9aad6e6da8a23c6a8dcb6d65cc4b56a06)
[task 2022-06-17T10:27:23.203Z] 10:27:23     INFO -  PID 19137 | SUMMARY: ThreadSanitizer: data race /builds/worker/checkouts/gecko/tools/profiler/core/platform.cpp:2591:37 in StreamMarkerSchema
[task 2022-06-17T10:27:23.203Z] 10:27:23     INFO -  PID 19137 | ==================
[task 2022-06-17T10:27:23.204Z] 10:27:23     INFO -  <<<<<<<
[task 2022-06-17T10:27:23.204Z] 10:27:23     INFO -  TEST-START | tools/profiler/tests/xpcshell/test_active_configuration.js

Hello Gerald, can you please take a look at this? I think this might be caused by Bug 1768722.
Thanks!

Flags: needinfo?(gsquelart)

The backfills looks like it's caused by Bug 1770087, Florian can you please take a look? backfills

Flags: needinfo?(gsquelart) → needinfo?(florian)
Blocks: tsan
Group: core-security → dom-core-security

Though it looks like a race to access the marker schema table, between adding a marker and outputting that marker (these two operations should be separated by profiler_stop()).
This code was added a long time ago, maybe bug 1770087 just made it more likely to happen. Anyway, I should look into it.

Severity: -- → S3
Flags: needinfo?(gsquelart)
Priority: -- → P2

(In reply to Gerald Squelart [:gerald] (he/him) from comment #3)

it looks like a race to access the marker schema table, between adding a marker and outputting that marker (these two operations should be separated by profiler_stop()).

I was incorrect in my quick first thoughts about profiler_stop(): Profiles are always streamed before we stop the profiler; sometimes profiling is paused but not always (especially in tests).
And even then, we could theoretically still suffer from this race, something like:

  1. T1: Start profiling...
  2. T2: Start recording a marker, first check if profiling is active, it is.
  3. T1: Stop profiling, set atomic is-profiling variable to false.
  4. T2: Continue with the marker, request tag for our marker type, which may write into the marker tag table sMarkerTypeFunctions1Based.
    T1: Stream markers, access marker tag table.

However, while it looks like there could indeed be a race to sMarkerTypeFunctions1Based, I believe there is no actual race with individual items of that table, because:

  • We only write into the table when there is a new marker type.
  • The marker tag associated with this write is only then written into the profile buffer (guarded by its mutex).
  • When streaming a marker, we have locked the profile buffer mutex, we then read the marker tag, and then we access the table at the index associated with that tag.

As the TSAN report notes, there is a Read of size 8 at 0x561bfb8cd980 by main thread (mutexes: write M0), and a Previous write of size 8 at 0x561bfb8cd980 by thread T4 -- since M0 is not held in the previous write, it infers there is a race, but I believe it doesn't see the effective barrier created by the M0-protected write of the tag into the buffer.

So in the end, I believe there is no actual race, and certainly no security issue (our code controls all reads&writes to that statically-zero-initialized table, without user-provided data).

In any case, I can add a bit more explicit thread-safety at a small runtime cost. I could add some atomic accesses (to table elements, or around accesses) to remove this apparent race.

Assignee: nobody → gsquelart
Flags: needinfo?(gsquelart)
Flags: needinfo?(florian)
Group: dom-core-security

To avoid real or apparent races to the list of marker schema functions, some
bits of the atomic count are used to effectively implement a RWLock, so that
any number of threads can add their own new marker schema concurrently, while
the profile-capture reading of the whole list can only be done on its own.

Pushed by gsquelart@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/82e6caebcd8c
Added atomic locking around marker schema functions - r=florian
Status: NEW → RESOLVED
Closed: 2 years ago
Resolution: --- → FIXED
Target Milestone: --- → 106 Branch
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Created:
Updated:
Size: