1626631 - Intermittent GECKO(1274) | SUMMARY: ThreadSanitizer: data race /builds/worker/checkouts/gecko/js/src/gc/Cell.h:730:19 in unsafeSetPtr

Status: RESOLVED FIXED

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

Description

[Treeherder Bug Filer]

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

---

[task 2020-04-01T12:49:15.952Z] 12:49:15 INFO - TEST-START | dom/animation/test/style/test_transform-non-normalizable-rotate3d.html
[task 2020-04-01T12:49:16.330Z] 12:49:16 INFO - GECKO(1274) | MEMORY STAT | vsize 130550524MB | residentFast 559MB
[task 2020-04-01T12:49:16.849Z] 12:49:16 INFO - GECKO(1274) | ==================
[task 2020-04-01T12:49:16.849Z] 12:49:16 INFO - GECKO(1274) | WARNING: ThreadSanitizer: data race (pid=1274)
[task 2020-04-01T12:49:16.850Z] 12:49:16 INFO - GECKO(1274) | Write of size 8 at 0x7fd0281a40c0 by thread T10:
[task 2020-04-01T12:49:16.850Z] 12:49:16 INFO - GECKO(1274) | #0 unsafeSetPtr /builds/worker/checkouts/gecko/js/src/gc/Cell.h:730:19 (libxul.so+0x6be0ba8)
[task 2020-04-01T12:49:16.850Z] 12:49:16 INFO - GECKO(1274) | #1 TraceNullableEdge<js::Shape> /builds/worker/checkouts/gecko/js/src/gc/Tracer.h:172:15 (libxul.so+0x6be0ba8)
[task 2020-04-01T12:49:16.851Z] 12:49:16 INFO - GECKO(1274) | #2 js::Scope::traceChildren(JSTracer*) /builds/worker/checkouts/gecko/js/src/gc/Marking.cpp:1370:3 (libxul.so+0x6be0ba8)
[task 2020-04-01T12:49:16.851Z] 12:49:16 INFO - GECKO(1274) | #3 UpdateCellPointers<js::Scope> /builds/worker/checkouts/gecko/js/src/gc/GC.cpp:2178:9 (libxul.so+0x6ba836c)
[task 2020-04-01T12:49:16.851Z] 12:49:16 INFO - GECKO(1274) | #4 UpdateArenaPointersTyped<js::Scope> /builds/worker/checkouts/gecko/js/src/gc/GC.cpp:2184:5 (libxul.so+0x6ba836c)
[task 2020-04-01T12:49:16.851Z] 12:49:16 INFO - GECKO(1274) | #5 UpdateArenaPointers /builds/worker/checkouts/gecko/js/src/gc/GC.cpp:2213:5 (libxul.so+0x6ba836c)
[task 2020-04-01T12:49:16.852Z] 12:49:16 INFO - GECKO(1274) | #6 UpdateArenaListSegmentPointers(js::gc::GCRuntime*, ArenaListSegment const&) /builds/worker/checkouts/gecko/js/src/gc/GC.cpp:2237:5 (libxul.so+0x6ba836c)
[task 2020-04-01T12:49:16.852Z] 12:49:16 INFO - GECKO(1274) | #7 js::gc::ParallelWorker<ArenaListSegment, ArenasToUpdate>::run() /builds/worker/checkouts/gecko/js/src/gc/ParallelWork.h:52:22 (libxul.so+0x6bda0e4)
[task 2020-04-01T12:49:16.852Z] 12:49:16 INFO - GECKO(1274) | #8 js::GCParallelTask::runTask() /builds/worker/checkouts/gecko/js/src/gc/GCParallelTask.cpp:146:3 (libxul.so+0x6bcdeaf)
[task 2020-04-01T12:49:16.852Z] 12:49:16 INFO - GECKO(1274) | #9 js::GCParallelTask::runFromHelperThread(js::AutoLockHelperThreadState&) /builds/worker/checkouts/gecko/js/src/gc/GCParallelTask.cpp:131:5 (libxul.so+0x6bcdd3e)
[task 2020-04-01T12:49:16.853Z] 12:49:16 INFO - GECKO(1274) | #10 js::HelperThread::handleGCParallelWorkload(js::AutoLockHelperThreadState&) /builds/worker/checkouts/gecko/js/src/vm/HelperThreads.cpp:1712:21 (libxul.so+0x667cb22)
[task 2020-04-01T12:49:16.853Z] 12:49:16 INFO - GECKO(1274) | #11 js::HelperThread::threadLoop() /builds/worker/checkouts/gecko/js/src/vm/HelperThreads.cpp:2526:5 (libxul.so+0x667e8b7)
[task 2020-04-01T12:49:16.853Z] 12:49:16 INFO - GECKO(1274) | #12 js::HelperThread::ThreadMain(void*) /builds/worker/checkouts/gecko/js/src/vm/HelperThreads.cpp:2048:11 (libxul.so+0x667ad5d)
[task 2020-04-01T12:49:16.853Z] 12:49:16 INFO - GECKO(1274) | #13 callMain<0> /builds/worker/checkouts/gecko/js/src/threading/Thread.h:217:5 (libxul.so+0x66bbe70)
[task 2020-04-01T12:49:16.854Z] 12:49:16 INFO - GECKO(1274) | #14 js::detail::ThreadTrampoline<void (&)(void*), js::HelperThread*>::Start(void*) /builds/worker/checkouts/gecko/js/src/threading/Thread.h:206:11 (libxul.so+0x66bbe70)
[task 2020-04-01T12:49:16.854Z] 12:49:16 INFO - GECKO(1274) | Previous read of size 8 at 0x7fd0281a40c0 by thread T15:
[task 2020-04-01T12:49:16.854Z] 12:49:16 INFO - GECKO(1274) | [failed to restore the stack]
[task 2020-04-01T12:49:16.854Z] 12:49:16 INFO - GECKO(1274) | Thread T10 'JS Helper' (tid=1291, running) created by main thread at:
[task 2020-04-01T12:49:16.855Z] 12:49:16 INFO - GECKO(1274) | #0 pthread_create /builds/worker/fetches/llvm-project/llvm/projects/compiler-rt/lib/tsan/rtl/tsan_interceptors.cc:967:3 (firefox+0x571ab)
[task 2020-04-01T12:49:16.855Z] 12:49:16 INFO - GECKO(1274) | #1 js::Thread::create(void* ()(void), void*) /builds/worker/checkouts/gecko/js/src/threading/posix/PosixThread.cpp:52:7 (libxul.so+0x657c6e3)
[task 2020-04-01T12:49:16.855Z] 12:49:16 INFO - GECKO(1274) | #2 bool js::Thread::init<void (&)(void*), js::HelperThread*>(void (&)(void*), js::HelperThread*&&) /builds/worker/checkouts/gecko/js/src/threading/Thread.h:90:12 (libxul.so+0x667ac72)
[task 2020-04-01T12:49:16.855Z] 12:49:16 INFO - GECKO(1274) | #3 js::GlobalHelperThreadState::ensureInitialized() /builds/worker/checkouts/gecko/js/src/vm/HelperThreads.cpp:1158:27 (libxul.so+0x66758ca)
[task 2020-04-01T12:49:16.856Z] 12:49:16 INFO - GECKO(1274) | #4 js::EnsureHelperThreadsInitialized() /builds/worker/checkouts/gecko/js/src/vm/HelperThreads.cpp:94:30 (libxul.so+0x6675512)
[task 2020-04-01T12:49:16.856Z] 12:49:16 INFO - GECKO(1274) | #5 JSRuntime::init(JSContext*, unsigned int) /builds/worker/checkouts/gecko/js/src/vm/Runtime.cpp:200:32 (libxul.so+0x6782c62)
[task 2020-04-01T12:49:16.856Z] 12:49:16 INFO - GECKO(1274) | #6 js::NewContext(unsigned int, JSRuntime*) /builds/worker/checkouts/gecko/js/src/vm/JSContext.cpp:170:17 (libxul.so+0x66c393d)
[task 2020-04-01T12:49:16.857Z] 12:49:16 INFO - GECKO(1274) | #7 JS_NewContext(unsigned int, JSRuntime*) /builds/worker/checkouts/gecko/js/src/jsapi.cpp:392:10 (libxul.so+0x6509704)
[task 2020-04-01T12:49:16.857Z] 12:49:16 INFO - GECKO(1274) | #8 mozilla::CycleCollectedJSContext::Initialize(JSRuntime*, unsigned int) /builds/worker/checkouts/gecko/xpcom/base/CycleCollectedJSContext.cpp:128:16 (libxul.so+0x9ce91b)
[task 2020-04-01T12:49:16.857Z] 12:49:16 INFO - GECKO(1274) | #9 XPCJSContext::Initialize() /builds/worker/checkouts/gecko/js/xpconnect/src/XPCJSContext.cpp:1104:32 (libxul.so+0x18c687a)
[task 2020-04-01T12:49:16.857Z] 12:49:16 INFO - GECKO(1274) | #10 XPCJSContext::NewXPCJSContext() /builds/worker/checkouts/gecko/js/xpconnect/src/XPCJSContext.cpp:1300:23 (libxul.so+0x18c73d7)
[task 2020-04-01T12:49:16.858Z] 12:49:16 INFO - GECKO(1274) | #11 nsXPConnect::InitJSContext() /builds/worker/checkouts/gecko/js/xpconnect/src/nsXPConnect.cpp:80:25 (libxul.so+0x1900ef3)
[task 2020-04-01T12:49:16.858Z] 12:49:16 INFO - GECKO(1274) | #12 xpc::InitializeJSContext() /builds/worker/checkouts/gecko/js/xpconnect/src/nsXPConnect.cpp:98:35 (libxul.so+0x1900faf)
[task 2020-04-01T12:49:16.858Z] 12:49:16 INFO - GECKO(1274) | #13 XREMain::XRE_mainRun() /builds/worker/checkouts/gecko/toolkit/xre/nsAppRunner.cpp:4399:5 (libxul.so+0x6334c5f)
[task 2020-04-01T12:49:16.858Z] 12:49:16 INFO - GECKO(1274) | #14 XREMain::XRE_main(int, char**, mozilla::BootstrapConfig const&) /builds/worker/checkouts/gecko/toolkit/xre/nsAppRunner.cpp:4761:8 (libxul.so+0x6335ef3)
[task 2020-04-01T12:49:16.859Z] 12:49:16 INFO - GECKO(1274) | #15 XRE_main(int, char**, mozilla::BootstrapConfig const&) /builds/worker/checkouts/gecko/toolkit/xre/nsAppRunner.cpp:4812:21 (libxul.so+0x6336244)
[task 2020-04-01T12:49:16.859Z] 12:49:16 INFO - GECKO(1274) | #16 mozilla::BootstrapImpl::XRE_main(int, char**, mozilla::BootstrapConfig const&) /builds/worker/checkouts/gecko/toolkit/xre/Bootstrap.cpp:45:12 (libxul.so+0x6340df2)
[task 2020-04-01T12:49:16.859Z] 12:49:16 INFO - GECKO(1274) | #17 do_main /builds/worker/checkouts/gecko/browser/app/nsBrowserApp.cpp:217:22 (firefox+0xc8b63)
[task 2020-04-01T12:49:16.859Z] 12:49:16 INFO - GECKO(1274) | #18 main /builds/worker/checkouts/gecko/browser/app/nsBrowserApp.cpp:331:16 (firefox+0xc8b63)
[task 2020-04-01T12:49:16.860Z] 12:49:16 INFO - GECKO(1274) | Thread T15 'JS Helper' (tid=1296, running) created by main thread at:
[task 2020-04-01T12:49:16.860Z] 12:49:16 INFO - GECKO(1274) | #0 pthread_create /builds/worker/fetches/llvm-project/llvm/projects/compiler-rt/lib/tsan/rtl/tsan_interceptors.cc:967:3 (firefox+0x571ab)
[task 2020-04-01T12:49:16.860Z] 12:49:16 INFO - GECKO(1274) | #1 js::Thread::create(void* ()(void), void*) /builds/worker/checkouts/gecko/js/src/threading/posix/PosixThread.cpp:52:7 (libxul.so+0x657c6e3)
[task 2020-04-01T12:49:16.860Z] 12:49:16 INFO - GECKO(1274) | #2 bool js::Thread::init<void (&)(void*), js::HelperThread*>(void (&)(void*), js::HelperThread*&&) /builds/worker/checkouts/gecko/js/src/threading/Thread.h:90:12 (libxul.so+0x667ac72)
[task 2020-04-01T12:49:16.862Z] 12:49:16 INFO - GECKO(1274) | #3 js::GlobalHelperThreadState::ensureInitialized() /builds/worker/checkouts/gecko/js/src/vm/HelperThreads.cpp:1158:27 (libxul.so+0x66758ca)
[task 2020-04-01T12:49:16.862Z] 12:49:16 INFO - GECKO(1274) | #4 js::EnsureHelperThreadsInitialized() /builds/worker/checkouts/gecko/js/src/vm/HelperThreads.cpp:94:30 (libxul.so+0x6675512)
[task 2020-04-01T12:49:16.862Z] 12:49:16 INFO - GECKO(1274) | #5 JSRuntime::init(JSContext*, unsigned int) /builds/worker/checkouts/gecko/js/src/vm/Runtime.cpp:200:32 (libxul.so+0x6782c62)
[task 2020-04-01T12:49:16.862Z] 12:49:16 INFO - GECKO(1274) | #6 js::NewContext(unsigned int, JSRuntime*) /builds/worker/checkouts/gecko/js/src/vm/JSContext.cpp:170:17 (libxul.so+0x66c393d)
[task 2020-04-01T12:49:16.863Z] 12:49:16 INFO - GECKO(1274) | #7 JS_NewContext(unsigned int, JSRuntime*) /builds/worker/checkouts/gecko/js/src/jsapi.cpp:392:10 (libxul.so+0x6509704)
[task 2020-04-01T12:49:16.863Z] 12:49:16 INFO - GECKO(1274) | #8 mozilla::CycleCollectedJSContext::Initialize(JSRuntime*, unsigned int) /builds/worker/checkouts/gecko/xpcom/base/CycleCollectedJSContext.cpp:128:16 (libxul.so+0x9ce91b)
[task 2020-04-01T12:49:16.863Z] 12:49:16 INFO - GECKO(1274) | #9 XPCJSContext::Initialize() /builds/worker/checkouts/gecko/js/xpconnect/src/XPCJSContext.cpp:1104:32 (libxul.so+0x18c687a)
[task 2020-04-01T12:49:16.863Z] 12:49:16 INFO - GECKO(1274) | #10 XPCJSContext::NewXPCJSContext() /builds/worker/checkouts/gecko/js/xpconnect/src/XPCJSContext.cpp:1300:23 (libxul.so+0x18c73d7)
[task 2020-04-01T12:49:16.864Z] 12:49:16 INFO - GECKO(1274) | #11 nsXPConnect::InitJSContext() /builds/worker/checkouts/gecko/js/xpconnect/src/nsXPConnect.cpp:80:25 (libxul.so+0x1900ef3)
[task 2020-04-01T12:49:16.865Z] 12:49:16 INFO - GECKO(1274) | #12 xpc::InitializeJSContext() /builds/worker/checkouts/gecko/js/xpconnect/src/nsXPConnect.cpp:98:35 (libxul.so+0x1900faf)
[task 2020-04-01T12:49:16.865Z] 12:49:16 INFO - GECKO(1274) | #13 XREMain::XRE_mainRun() /builds/worker/checkouts/gecko/toolkit/xre/nsAppRunner.cpp:4399:5 (libxul.so+0x6334c5f)
[task 2020-04-01T12:49:16.866Z] 12:49:16 INFO - GECKO(1274) | #14 XREMain::XRE_main(int, char**, mozilla::BootstrapConfig const&) /builds/worker/checkouts/gecko/toolkit/xre/nsAppRunner.cpp:4761:8 (libxul.so+0x6335ef3)
[task 2020-04-01T12:49:16.866Z] 12:49:16 INFO - GECKO(1274) | #15 XRE_main(int, char**, mozilla::BootstrapConfig const&) /builds/worker/checkouts/gecko/toolkit/xre/nsAppRunner.cpp:4812:21 (libxul.so+0x6336244)
[task 2020-04-01T12:49:16.866Z] 12:49:16 INFO - GECKO(1274) | #16 mozilla::BootstrapImpl::XRE_main(int, char**, mozilla::BootstrapConfig const&) /builds/worker/checkouts/gecko/toolkit/xre/Bootstrap.cpp:45:12 (libxul.so+0x6340df2)
[task 2020-04-01T12:49:16.866Z] 12:49:16 INFO - GECKO(1274) | #17 do_main /builds/worker/checkouts/gecko/browser/app/nsBrowserApp.cpp:217:22 (firefox+0xc8b63)
[task 2020-04-01T12:49:16.868Z] 12:49:16 INFO - GECKO(1274) | #18 main /builds/worker/checkouts/gecko/browser/app/nsBrowserApp.cpp:331:16 (firefox+0xc8b63)
[task 2020-04-01T12:49:16.868Z] 12:49:16 INFO - GECKO(1274) | SUMMARY: ThreadSanitizer: data race /builds/worker/checkouts/gecko/js/src/gc/Cell.h:730:19 in unsafeSetPtr
[task 2020-04-01T12:49:16.868Z] 12:49:16 INFO - GECKO(1274) | ==================
[task 2020-04-01T12:49:16.932Z] 12:49:16 INFO - GECKO(1274) | Exiting due to channel error.
[task 2020-04-01T12:49:16.932Z] 12:49:16 INFO - GECKO(1274) | Exiting due to channel error.
[task 2020-04-01T12:49:16.932Z] 12:49:16 INFO - GECKO(1274) | Exiting due to channel error.
[task 2020-04-01T12:49:16.934Z] 12:49:16 INFO - GECKO(1274) | Exiting due to channel error.
[task 2020-04-01T12:49:18.037Z] 12:49:18 INFO - GECKO(1274) | Crash Annotation GraphicsCriticalError: |[C0][GFX1-]: Receive IPC close with reason=AbnormalShutdown (t=73.2576) Crash Annotation GraphicsCriticalError: |[C0][GFX1-]: Receive IPC close with reason=AbnormalShutdown (t=67.2387) Crash Annotation GraphicsCriticalError: |[C0][GFX1-]: Receive IPC close with reason=AbnormalShutdown (t=83.6249) Crash Annotation GraphicsCriticalError: |[C0][GFX1-]: Receive IPC close with reason=AbnormalShutdown (t=85.1221)
[task 2020-04-01T12:49:18.073Z] 12:49:18 INFO - TEST-INFO | Main app process: killed by SIGIOT
[task 2020-04-01T12:49:18.073Z] 12:49:18 INFO - Buffered messages logged at 12:49:16
[task 2020-04-01T12:49:18.073Z] 12:49:18 INFO - TEST-PASS | dom/animation/test/style/test_transform-non-normalizable-rotate3d.html | - : Elided 2 passes or known failures.
[task 2020-04-01T12:49:18.073Z] 12:49:18 INFO - Buffered messages finished
[task 2020-04-01T12:49:18.073Z] 12:49:18 ERROR - TEST-UNEXPECTED-FAIL | dom/animation/test/style/test_transform-non-normalizable-rotate3d.html | application terminated with exit code -6
[task 2020-04-01T12:49:18.073Z] 12:49:18 INFO - runtests.py | Application ran for: 0:01:43.632334
[task 2020-04-01T12:49:18.074Z] 12:49:18 INFO - zombiecheck | Reading PID log: /tmp/tmpKAn2G7pidlog
[task 2020-04-01T12:49:18.074Z] 12:49:18 INFO - ==> process 1274 launched child process 1289
[task 2020-04-01T12:49:18.074Z] 12:49:18 INFO - ==> process 1274 launched child process 1350
[task 2020-04-01T12:49:18.074Z] 12:49:18 INFO - ==> process 1274 launched child process 1419
[task 2020-04-01T12:49:18.074Z] 12:49:18 INFO - ==> process 1274 launched child process 1489
[task 2020-04-01T12:49:18.074Z] 12:49:18 INFO - ==> process 1274 launched child process 1519
[task 2020-04-01T12:49:18.075Z] 12:49:18 INFO - zombiecheck | Checking for orphan process with PID: 1289
[task 2020-04-01T12:49:18.075Z] 12:49:18 INFO - zombiecheck | Checking for orphan process with PID: 1419
[task 2020-04-01T12:49:18.075Z] 12:49:18 INFO - zombiecheck | Checking for orphan process with PID: 1519
[task 2020-04-01T12:49:18.075Z] 12:49:18 INFO - zombiecheck | Checking for orphan process with PID: 1350
[task 2020-04-01T12:49:18.075Z] 12:49:18 INFO - zombiecheck | Checking for orphan process with PID: 1489
[task 2020-04-01T12:49:18.075Z] 12:49:18 INFO - Stopping web server
[task 2020-04-01T12:49:18.091Z] 12:49:18 INFO - Stopping web socket server
[task 2020-04-01T12:49:18.111Z] 12:49:18 INFO - Stopping ssltunnel
[task 2020-04-01T12:49:18.132Z] 12:49:18 WARNING - leakcheck | refcount logging is off, so leaks can't be detected!
[task 2020-04-01T12:49:18.132Z] 12:49:18 INFO - runtests.py | Running tests: end.
[task 2020-04-01T12:49:18.152Z] 12:49:18 INFO - Buffered messages finished
[task 2020-04-01T12:49:18.152Z] 12:49:18 INFO - Running manifest: dom/crypto/test/mochitest.ini
[task 2020-04-01T12:49:18.180Z] 12:49:18 INFO - Setting pipeline to PAUSED ...
[task 2020-04-01T12:49:18.180Z] 12:49:18 INFO - Pipeline is PREROLLING ...
[task 2020-04-01T12:49:18.180Z] 12:49:18 INFO - Pipeline is PREROLLED ...
[task 2020-04-01T12:49:18.180Z] 12:49:18 INFO - Setting pipeline to PLAYING ...
[task 2020-04-01T12:49:18.181Z] 12:49:18 INFO - New clock: GstSystemClock
[task 2020-04-01T12:49:18.216Z] 12:49:18 INFO - Got EOS from element "pipeline0".
[task 2020-04-01T12:49:18.216Z] 12:49:18 INFO - Execution ended after 0:00:00.033481771
[task 2020-04-01T12:49:18.217Z] 12:49:18 INFO - Setting pipeline to PAUSED ...
[task 2020-04-01T12:49:18.217Z] 12:49:18 INFO - Setting pipeline to READY ...
[task 2020-04-01T12:49:18.217Z] 12:49:18 INFO - (gst-launch-1.0:1572): GStreamer-CRITICAL *: 12:49:18.212: gst_object_unref: assertion '((GObject ) object)->ref_count > 0' failed
[task 2020-04-01T12:49:18.217Z] 12:49:18 INFO - Setting pipeline to NULL ...
[task 2020-04-01T12:49:18.217Z] 12:49:18 INFO - Freeing pipeline ...
[task 2020-04-01T12:49:18.238Z] 12:49:18 INFO - INFO | runtests.py | TSan using symbolizer at /builds/worker/workspace/build/application/firefox/llvm-symbolizer
[task 2020-04-01T12:49:18.910Z] 12:49:18 INFO - pk12util: PKCS12 IMPORT SUCCESSFUL
[task 2020-04-01T12:49:18.991Z] 12:49:18 INFO - INFO | runtests.py | TSan using symbolizer at /builds/worker/workspace/build/application/firefox/llvm-symbolizer
[task 2020-04-01T12:49:18.991Z] 12:49:18 INFO - INFO | runtests.py | TSan using symbolizer at /builds/worker/workspace/build/application/firefox/llvm-symbolizer
[task 2020-04-01T12:49:18.992Z] 12:49:18 INFO - MochitestServer : launching [u'/builds/worker/workspace/build/tests/bin/xpcshell', '-g', '/builds/worker/workspace/build/application/firefox', '-f', '/builds/worker/workspace/build/tests/bin/components/httpd.js', '-e', "const _PROFILE_PATH = '/tmp/tmpSqS4Jw.mozrunner'; const _SERVER_PORT = '8888'; const _SERVER_ADDR = '127.0.0.1'; const _TEST_PREFIX = undefined; const _DISPLAY_RESULTS = false;", '-f', '/builds/worker/workspace/build/tests/mochitest/server.js']
[task 2020-04-01T12:49:18.994Z] 12:49:18 INFO - runtests.py | Server pid: 1591
[task 2020-04-01T12:49:18.997Z] 12:49:18 INFO - runtests.py | Websocket server pid: 1594
[task 2020-04-01T12:49:18.998Z] 12:49:18 INFO - INFO | runtests.py | TSan using symbolizer at /builds/worker/workspace/build/application/firefox/llvm-symbolizer
[task 2020-04-01T12:49:19.006Z] 12:49:19 INFO - runtests.py | SSL tunnel pid: 1597
[task 2020-04-01T12:49:19.759Z] 12:49:19 INFO - runtests.py | Running with scheme: https
[task 2020-04-01T12:49:19.759Z] 12:49:19 INFO - runtests.py | Running with e10s: True
[task 2020-04-01T12:49:19.759Z] 12:49:19 INFO - runtests.py | Running with fission: False
[task 2020-04-01T12:49:19.759Z] 12:49:19 INFO - runtests.py | Running with serviceworker_e10s: True
[task 2020-04-01T12:49:19.760Z] 12:49:19 INFO - runtests.py | Running with socketprocess_e10s: False
[task 2020-04-01T12:49:19.760Z] 12:49:19 INFO - runtests.py | Running tests: start.
[task 2020-04-01T12:49:19.760Z] 12:49:19 INFO -
[task 2020-04-01T12:49:19.780Z] 12:49:19 INFO - Application command: /builds/worker/workspace/build/application/firefox/firefox -marionette -foreground -profile /tmp/tmpSqS4Jw.mozrunner
[task 2020-04-01T12:49:19.788Z] 12:49:19 INFO - runtests.py | Application pid: 1620
[task 2020-04-01T12:49:19.788Z] 12:49:19 INFO - TEST-INFO | started process GECKO(1620)
[task 2020-04-01T12:49:24.655Z] 12:49:24 INFO - GECKO(1620) | 1585745364646 [e-mail] WARN Loading extension '[e-mail]': Reading manifest: Invalid extension permission: networkStatus
[task 2020-04-01T12:49:29.987Z] 12:49:29 INFO - GECKO(1620) | 1585745369974 [e-mail] WARN Loading extension '[e-mail]': Reading manifest: Invalid extension permission: mozillaAddons
[task 2020-04-01T12:49:29.987Z] 12:49:29 INFO - GECKO(1620) | 1585745369976 [e-mail] WARN Loading extension '[e-mail]': Reading manifest: Invalid extension permission: telemetry
[task 2020-04-01T12:49:29.987Z] 12:49:29 INFO - GECKO(1620) | 1585745369978 [e-mail] WARN Loading extension '[e-mail]': Reading manifest: Invalid extension permission: resource://pdf.js/
[task 2020-04-01T12:49:29.987Z] 12:49:29 INFO - GECKO(1620) | 1585745369979 [e-mail] WARN Loading extension '[e-mail]': Reading manifest: Invalid extension permission: about:reader
[task 2020-04-01T12:49:31.029Z] 12:49:31 INFO - GECKO(1620) | 1585745371015 Marionette TRACE Marionette enabled
[task 2020-04-01T12:49:32.132Z] 12:49:32 INFO - GECKO(1620) | 1585745372116 Marionette TRACE Received observer notification toplevel-window-ready
[task 2020-04-01T12:49:39.932Z] 12:49:39 INFO - GECKO(1620) | ==1684==WARNING: Symbolizer buffer too small
[task 2020-04-01T12:49:39.932Z] 12:49:39 INFO - GECKO(1620) | ==1684==WARNING: Symbolizer buffer too small
[task 2020-04-01T12:49:40.356Z] 12:49:40 INFO - GECKO(1620) | ==1684==WARNING: Symbolizer buffer too small
[task 2020-04-01T12:49:40.356Z] 12:49:40 INFO - GECKO(1620) | ==1684==WARNING: Symbolizer buffer too small
[task 2020-04-01T12:49:40.364Z] 12:49:40 INFO - GECKO(1620) | ==1684==WARNING: Symbolizer buffer too small
[task 2020-04-01T12:49:40.364Z] 12:49:40 INFO - GECKO(1620) | ==1684==WARNING: Symbolizer buffer too small
[task 2020-04-01T12:49:40.364Z] 12:49:40 INFO - GECKO(1620) | ==1684==WARNING: Symbolizer buffer too small
[task 2020-04-01T12:49:40.364Z] 12:49:40 INFO - GECKO(1620) | ==1684==WARNING: Symbolizer buffer too small
[task 2020-04-01T12:49:40.372Z] 12:49:40 INFO - GECKO(1620) | ==1684==WARNING: Symbolizer buffer too small
[task 2020-04-01T12:49:40.373Z] 12:49:40 INFO - GECKO(1620) | ==1684==WARNING: Symbolizer buffer too small
[task 2020-04-01T12:49:40.373Z] 12:49:40 INFO - GECKO(1620) | ==1684==WARNING: Symbolizer buffer too small
[task 2020-04-01T12:49:40.373Z] 12:49:40 INFO - GECKO(1620) | ==1684==WARNING: Symbolizer buffer too small
[task 2020-04-01T12:49:40.374Z] 12:49:40 INFO - GECKO(1620) | ==1684==WARNING: Symbolizer buffer too small
[task 2020-04-01T12:49:40.374Z] 12:49:40 INFO - GECKO(1620) | ==1684==WARNING: Symbolizer buffer too small
[task 2020-04-01T12:49:40.374Z] 12:49:40 INFO - GECKO(1620) | ==1684==WARNING: Symbolizer buffer too small
[task 2020-04-01T12:49:40.375Z] 12:49:40 INFO - GECKO(1620) | ==1684==WARNING: Symbolizer buffer too small
[task 2020-04-01T12:49:40.382Z] 12:49:40 INFO - GECKO(1620) | ==1684==WARNING: Symbolizer buffer too small
[task 2020-04-01T12:49:40.383Z] 12:49:40 INFO - GECKO(1620) | ==1684==WARNING: Symbolizer buffer too small
[task 2020-04-01T12:49:40.383Z] 12:49:40 INFO - GECKO(1620) | ==1684==WARNING: Symbolizer buffer too small
[task 2020-04-01T12:49:40.383Z] 12:49:40 INFO - GECKO(1620) | ==1684==WARNING: Symbolizer buffer too small
[task 2020-04-01T12:49:40.386Z] 12:49:40 INFO - GECKO(1620) | ==1684==WARNING: Symbolizer buffer too small
[task 2020-04-01T12:49:40.387Z] 12:49:40 INFO - GECKO(1620) | ==1684==WARNING: Symbolizer buffer too small
[task 2020-04-01T12:49:40.388Z] 12:49:40 INFO - GECKO(1620) | ==1684==WARNING: Symbolizer buffer too small
[task 2020-04-01T12:49:40.388Z] 12:49:40 INFO - GECKO(1620) | ==1684==WARNING: Symbolizer buffer too small
[task 2020-04-01T12:49:40.396Z] 12:49:40 INFO - GECKO(1620) | ==1684==WARNING: Symbolizer buffer too small
[task 2020-04-01T12:49:40.396Z] 12:49:40 INFO - GECKO(1620) | ==1684==WARNING: Symbolizer buffer too small
[task 2020-04-01T12:49:40.396Z] 12:49:40 INFO - GECKO(1620) | ==1684==WARNING: Symbolizer buffer too small
[task 2020-04-01T12:49:40.397Z] 12:49:40 INFO - GECKO(1620) | ==1684==WARNING: Symbolizer buffer too small
[task 2020-04-01T12:49:40.400Z] 12:49:40 INFO - GECKO(1620) | ==1684==WARNING: Symbolizer buffer too small
[task 2020-04-01T12:49:40.401Z] 12:49:40 INFO - GECKO(1620) | ==1684==WARNING: Symbolizer buffer too small
[task 2020-04-01T12:49:40.402Z] 12:49:40 INFO - GECKO(1620) | ==1684==WARNING: Symbolizer buffer too small
[task 2020-04-01T12:49:40.402Z] 12:49:40 INFO - GECKO(1620) | ==1684==WARNING: Symbolizer buffer too small
[task 2020-04-01T12:49:40.410Z] 12:49:40 INFO - GECKO(1620) | ==1684==WARNING: Symbolizer buffer too small
[task 2020-04-01T12:49:40.410Z] 12:49:40 INFO - GECKO(1620) | ==1684==WARNING: Symbolizer buffer too small
[task 2020-04-01T12:49:40.410Z] 12:49:40 INFO - GECKO(1620) | ==1684==WARNING: Symbolizer buffer too small
[task 2020-04-01T12:49:40.411Z] 12:49:40 INFO - GECKO(1620) | ==1684==WARNING: Symbolizer buffer too small
[task 2020-04-01T12:49:40.414Z] 12:49:40 INFO - GECKO(1620) | ==1684==WARNING: Symbolizer buffer too small
[task 2020-04-01T12:49:40.415Z] 12:49:40 INFO - GECKO(1620) | ==1684==WARNING: Symbolizer buffer too small
[task 2020-04-01T12:49:40.415Z] 12:49:40 INFO - GECKO(1620) | ==1684==WARNING: Symbolizer buffer too small
[task 2020-04-01T12:49:40.415Z] 12:49:40 INFO - GECKO(1620) | ==1684==WARNING: Symbolizer buffer too small
[task 2020-04-01T12:49:52.390Z] 12:49:52 INFO - GECKO(1620) | 1585745392387 Marionette TRACE Received observer notification marionette-startup-requested
[task 2020-04-01T12:49:52.391Z] 12:49:52 INFO - GECKO(1620) | 1585745392389 Marionette TRACE Waiting until startup recorder finished recording startup scripts...
[task 2020-04-01T12:49:52.547Z] 12:49:52 INFO - GECKO(1620) | 1585745392545 Marionette TRACE All scripts recorded.
[task 2020-04-01T12:49:53.369Z] 12:49:53 INFO - GECKO(1620) | 1585745393365 Marionette INFO Listening on port 2828
[task 2020-04-01T12:49:53.370Z] 12:49:53 INFO - GECKO(1620) | 1585745393367 Marionette DEBUG Marionette is listening
[task 2020-04-01T12:49:53.431Z] 12:49:53 INFO - GECKO(1620) | 1585745393424 Marionette DEBUG Accepted connection 0 from 127.0.0.1:36022
[task 2020-04-01T12:49:53.434Z] 12:49:53 INFO - GECKO(1620) | 1585745393431 Marionette DEBUG Closed connection 0
[task 2020-04-01T12:49:53.441Z] 12:49:53 INFO - GECKO(1620) | 1585745393436 Marionette DEBUG Accepted connection 1 from 127.0.0.1:36024
[task 2020-04-01T12:49:53.451Z] 12:49:53 INFO - GECKO(1620) | 1585745393444 Marionette DEBUG 1 -> [0,1,"WebDriver:NewSession",{"strictFileInteractability":true}]
[task 2020-04-01T12:49:53.794Z] 12:49:53 INFO - GECKO(1620) | 1585745393787 Marionette TRACE [16] Frame script loaded
[task 2020-04-01T12:49:53.810Z] 12:49:53 INFO - GECKO(1620) | 1585745393802 Marionette TRACE [16] Frame script registered
[task 2020-04-01T12:49:53.898Z] 12:49:53 INFO - GECKO(1620) | 1585745393893 Marionette DEBUG 1 <- [1,1,null,{"sessionId":"50ff72fb-0516-4868-8dd4-3be87f461af7","capabilities":{"browserName":"firefox","browserVersion":"76.0a ... p/tmpSqS4Jw.mozrunner","moz:shutdownTimeout":360000,"moz:useNonSpecCompliantPointerOrigin":false,"moz:webdriverClick":true}}]
[task 2020-04-01T12:49:53.979Z] 12:49:53 INFO - GECKO(1620) | 1585745393976 Marionette DEBUG 1 -> [0,2,"Addon:Install",{"path":"/tmp/tmpFSwpkE.zip","temporary":false}]
[task 2020-04-01T12:49:54.564Z] 12:49:54 INFO - GECKO(1620) | 1585745394557 Marionette DEBUG 1 <- [1,2,null,{"value":"[e-mail]"}]
[task 2020-04-01T12:49:54.652Z] 12:49:54 INFO - GECKO(1620) | 1585745394647 Marionette DEBUG 1 -> [0,3,"Addon:Install",{"path":"/tmp/tmpwjZATN.zip","temporary":false}]
[task 2020-04-01T12:49:55.454Z] 12:49:55 INFO - GECKO(1620) | 1585745395441 Marionette DEBUG 1 <- [1,3,null,{"value":"[e-mail]"}]
[task 2020-04-01T12:49:55.510Z] 12:49:55 INFO - GECKO(1620) | 1585745395498 Marionette DEBUG 1 -> [0,4,"Marionette:GetContext",{}]
[task 2020-04-01T12:49:55.510Z] 12:49:55 INFO - GECKO(1620) | 1585745395501 Marionette DEBUG 1 <- [1,4,null,{"value":"content"}]
[task 2020-04-01T12:49:55.517Z] 12:49:55 INFO - GECKO(1620) | 1585745395509 Marionette DEBUG 1 -> [0,5,"Marionette:SetContext",{"value":"chrome"}]
[task 2020-04-01T12:49:55.517Z] 12:49:55 INFO - GECKO(1620) | 1585745395512 Marionette DEBUG 1 <- [1,5,null,{"value":null}]
[task 2020-04-01T12:49:55.533Z] 12:49:55 INFO - GECKO(1620) | 1585745395520 Marionette DEBUG 1 -> [0,6,"WebDriver:ExecuteScript",{"script":"/ This Source Code Form is subject to the terms of the Mozilla Public\n * License, ... %2Ftmp&cleanupCrashes=true","flavor":"mochitest"}],"filename":"tests/mochitest/runtests.py","sandbox":"default","line":1793}]
[task 2020-04-01T12:49:55.561Z] 12:49:55 INFO - GECKO(1620) | 1585745395554 Marionette DEBUG 1 <- [1,6,null,{"value":null}]
[task 2020-04-01T12:49:55.698Z] 12:49:55 INFO - GECKO(1620) | 1585745395688 Marionette DEBUG 1 -> [0,7,"Marionette:SetContext",{"value":"content"}]
[task 2020-04-01T12:49:55.698Z] 12:49:55 INFO - GECKO(1620) | 1585745395692 Marionette DEBUG 1 <- [1,7,null,{"value":null}]
[task 2020-04-01T12:49:55.819Z] 12:49:55 INFO - GECKO(1620) | 1585745395811 Marionette DEBUG 1 -> [0,8,"WebDriver:DeleteSession",{}]
[task 2020-04-01T12:49:55.826Z] 12:49:55 INFO - GECKO(1620) | 1585745395822 Marionette DEBUG 1 <- [1,8,null,{"value":null}]
[task 2020-04-01T12:49:56.064Z] 12:49:56 INFO - runtests.py | Waiting for browser...
[task 2020-04-01T12:49:56.160Z] 12:49:56 INFO - GECKO(1620) | 1585745396155 Marionette DEBUG Closed connection 1
[task 2020-04-01T12:49:57.269Z] 12:49:57 INFO - GECKO(1620) | 1585745397266 Marionette TRACE [22] Frame script loaded
[task 2020-04-01T12:49:57.333Z] 12:49:57 INFO - GECKO(1620) | 1585745397330 Marionette ERROR [22] No reply from Marionette:Register

Comment 1

[Oana Pop-Rus]

Jon, please take a look.

Seems to be frequent failure from your push: https://treeherder.mozilla.org/#/jobs?repo=autoland&resultStatus=pending%2Crunning%2Csuccess%2Csuperseded%2Ctestfailed%2Cbusted%2Cexception%2Crunnable&searchStr=linux1804-64-tsan%2Copt%2Cmochitests%2Ctest-linux1804-64-tsan%2Fopt-mochitest-plain-e10s-6%2Cm%286%29&fromchange=483fcc9deed0a0d8b76f275da6ecd36ba689f9ca&selectedJob=295753447

Comment 2

[Cosmin Sabou [:CosminS]]

This was backed out by https://hg.mozilla.org/integration/autoland/rev/0a07f96b0b411e4867fa58a91738d542e1c3fce7
https://bugzilla.mozilla.org/show_bug.cgi?id=1625212#c26

Comment 3

[Intermittent Failures Robot]

53 failures in 883 pushes (0.06 failures/push) were associated with this bug yesterday.

Repository breakdown:

• autoland: 53

Platform breakdown:

• linux1804-64-tsan: 52
• macosx1014-64: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1626631&startday=2020-04-01&endday=2020-04-01&tree=all

Comment 4

[Intermittent Failures Robot]

53 failures in 5015 pushes (0.011 failures/push) were associated with this bug in the last 7 days.

This is the #15 most frequent failure this week.

** This failure happened more than 30 times this week! Resolving this bug is a high priority. **

** Try to resolve this bug as soon as possible. If unresolved for 2 weeks, the affected test(s) may be disabled. **

Repository breakdown:

• autoland: 53

Platform breakdown:

• linux1804-64-tsan: 52
• macosx1014-64: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1626631&startday=2020-03-30&endday=2020-04-05&tree=all