Filed by: malexandru [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer.html#?job_id=304370412&repo=autoland
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/f2TriKJdTwCVKW8CjUqTEg/runs/0/artifacts/public/logs/live_backing.log
[task 2020-05-30T06:08:48.378Z] 06:08:48 INFO - GECKO(2302) | Thread T25 'HTML5 Parser' (tid=2561, running) created by main thread at:
[task 2020-05-30T06:08:48.379Z] 06:08:48 INFO - GECKO(2302) | #0 pthread_create /builds/worker/fetches/llvm-project/llvm/projects/compiler-rt/lib/tsan/rtl/tsan_interceptors.cc:967:3 (firefox+0x584db)
[task 2020-05-30T06:08:48.379Z] 06:08:48 INFO - GECKO(2302) | #1 _PR_CreateThread /builds/worker/checkouts/gecko/nsprpub/pr/src/pthreads/ptthread.c:458:14 (libnspr4.so+0x3bf93)
[task 2020-05-30T06:08:48.380Z] 06:08:48 INFO - GECKO(2302) | #2 PR_CreateThread /builds/worker/checkouts/gecko/nsprpub/pr/src/pthreads/ptthread.c:533:12 (libnspr4.so+0x308c2)
[task 2020-05-30T06:08:48.380Z] 06:08:48 INFO - GECKO(2302) | #3 nsThread::Init(nsTSubstring<char> const&) /builds/worker/checkouts/gecko/xpcom/threads/nsThread.cpp:652:8 (libxul.so+0xb01acb)
[task 2020-05-30T06:08:48.381Z] 06:08:48 INFO - GECKO(2302) | #4 nsThreadManager::NewNamedThread(nsTSubstring<char> const&, unsigned int, nsIThread**) /builds/worker/checkouts/gecko/xpcom/threads/nsThreadManager.cpp:620:12 (libxul.so+0xb0815b)
[task 2020-05-30T06:08:48.381Z] 06:08:48 INFO - GECKO(2302) | #5 NS_NewNamedThread(nsTSubstring<char> const&, nsIThread**, already_AddRefed<nsIRunnable>, unsigned int) /builds/worker/checkouts/gecko/xpcom/threads/nsThreadUtils.cpp:157:57 (libxul.so+0xb0e6e8)
[task 2020-05-30T06:08:48.381Z] 06:08:48 INFO - GECKO(2302) | #6 NS_NewNamedThread<13> /builds/worker/workspace/obj-build/dist/include/nsThreadUtils.h:82:10 (libxul.so+0x1c9895a)
[task 2020-05-30T06:08:48.382Z] 06:08:48 INFO - GECKO(2302) | #7 nsHtml5Module::GetStreamParserThread() /builds/worker/checkouts/gecko/parser/html/nsHtml5Module.cpp:95:7 (libxul.so+0x1c9895a)
[task 2020-05-30T06:08:48.382Z] 06:08:48 INFO - GECKO(2302) | #8 nsHtml5StreamParser::nsHtml5StreamParser(nsHtml5TreeOpExecutor*, nsHtml5Parser*, eParserMode) /builds/worker/checkouts/gecko/parser/html/nsHtml5StreamParser.cpp:177:20 (libxul.so+0x1ca1f1b)
[task 2020-05-30T06:08:48.382Z] 06:08:48 INFO - GECKO(2302) | #9 nsHtml5Parser::MarkAsNotScriptCreated(char const*) /builds/worker/checkouts/gecko/parser/html/nsHtml5Parser.cpp:535:37 (libxul.so+0x1c9be02)
[task 2020-05-30T06:08:48.383Z] 06:08:48 INFO - GECKO(2302) | #10 nsHTMLDocument::StartDocumentLoad(char const*, nsIChannel*, nsILoadGroup*, nsISupports*, nsIStreamListener**, bool, nsIContentSink*) /builds/worker/checkouts/gecko/dom/html/nsHTMLDocument.cpp (libxul.so+0x3ac08f7)
[task 2020-05-30T06:08:48.383Z] 06:08:48 INFO - GECKO(2302) | #11 CreateDocument /builds/worker/checkouts/gecko/layout/build/nsContentDLF.cpp:319:13 (libxul.so+0x4fad943)
[task 2020-05-30T06:08:48.383Z] 06:08:48 INFO - GECKO(2302) | #12 nsContentDLF::CreateInstance(char const*, nsIChannel*, nsILoadGroup*, nsTSubstring<char> const&, nsIDocShell*, nsISupports*, nsIStreamListener**, nsIContentViewer**) /builds/worker/checkouts/gecko/layout/build/nsContentDLF.cpp:127:12 (libxul.so+0x4fad943)
[task 2020-05-30T06:08:48.383Z] 06:08:48 INFO - GECKO(2302) | #13 NewContentViewerObj /builds/worker/checkouts/gecko/docshell/base/nsDocShell.cpp:7709:35 (libxul.so+0x5ed43eb)
[task 2020-05-30T06:08:48.384Z] 06:08:48 INFO - GECKO(2302) | #14 nsDocShell::CreateContentViewer(nsTSubstring<char> const&, nsIRequest*, nsIStreamListener**) /builds/worker/checkouts/gecko/docshell/base/nsDocShell.cpp:7440:17 (libxul.so+0x5ed43eb)
[task 2020-05-30T06:08:48.384Z] 06:08:48 INFO - GECKO(2302) | #15 nsDSURIContentListener::DoContent(nsTSubstring<char> const&, bool, nsIRequest*, nsIStreamListener**, bool*) /builds/worker/checkouts/gecko/docshell/base/nsDSURIContentListener.cpp:182:20 (libxul.so+0x5ed39c0)
[task 2020-05-30T06:08:48.384Z] 06:08:48 INFO - GECKO(2302) | #16 nsDocumentOpenInfo::TryContentListener(nsIURIContentListener*, nsIChannel*) /builds/worker/checkouts/gecko/uriloader/base/nsURILoader.cpp:631:18 (libxul.so+0x1bbfb65)
[task 2020-05-30T06:08:48.384Z] 06:08:48 INFO - GECKO(2302) | #17 nsDocumentOpenInfo::TryDefaultContentListener(nsIChannel*) /builds/worker/checkouts/gecko/uriloader/base/nsURILoader.cpp:660:12 (libxul.so+0x1bc0710)
[task 2020-05-30T06:08:48.385Z] 06:08:48 INFO - GECKO(2302) | #18 nsDocumentOpenInfo::DispatchContent(nsIRequest*, nsISupports*) /builds/worker/checkouts/gecko/uriloader/base/nsURILoader.cpp:312:9 (libxul.so+0x1bbe846)
[task 2020-05-30T06:08:48.385Z] 06:08:48 INFO - GECKO(2302) | #19 nsDocumentOpenInfo::OnStartRequest(nsIRequest*) /builds/worker/checkouts/gecko/uriloader/base/nsURILoader.cpp:190:8 (libxul.so+0x1bbdd63)
[task 2020-05-30T06:08:48.385Z] 06:08:48 INFO - GECKO(2302) | #20 mozilla::net::HttpChannelChild::DoOnStartRequest(nsIRequest*, nsISupports*) /builds/worker/checkouts/gecko/netwerk/protocol/http/HttpChannelChild.cpp:691:20 (libxul.so+0x10c0d7e)
[task 2020-05-30T06:08:48.386Z] 06:08:48 INFO - GECKO(2302) | #21 mozilla::net::HttpChannelChild::OnStartRequest(mozilla::net::nsHttpResponseHead const&, bool const&, mozilla::net::nsHttpHeaderArray const&, mozilla::net::HttpChannelOnStartRequestArgs const&) /builds/worker/checkouts/gecko/netwerk/protocol/http/HttpChannelChild.cpp:538:3 (libxul.so+0x10c704c)
[task 2020-05-30T06:08:48.386Z] 06:08:48 INFO - GECKO(2302) | #22 operator() /builds/worker/checkouts/gecko/netwerk/protocol/http/HttpChannelChild.cpp:411:15 (libxul.so+0x10f8d51)
[task 2020-05-30T06:08:48.386Z] 06:08:48 INFO - GECKO(2302) | #23 std::_Function_handler<void (), mozilla::net::HttpChannelChild::RecvOnStartRequest(mozilla::net::nsHttpResponseHead const&, bool const&, mozilla::net::nsHttpHeaderArray const&, mozilla::net::HttpChannelOnStartRequestArgs const&)::$_9>::_M_invoke(std::_Any_data const&) /builds/worker/fetches/clang/bin/../lib/gcc/x86_64-unknown-linux-gnu/7.4.0/../../../../include/c++/7.4.0/bits/std_function.h:316:2 (libxul.so+0x10f8d51)
[task 2020-05-30T06:08:48.386Z] 06:08:48 INFO - GECKO(2302) | #24 operator() /builds/worker/fetches/clang/bin/../lib/gcc/x86_64-unknown-linux-gnu/7.4.0/../../../../include/c++/7.4.0/bits/std_function.h:706:14 (libxul.so+0x1037543)
[task 2020-05-30T06:08:48.387Z] 06:08:48 INFO - GECKO(2302) | #25 mozilla::net::ChannelFunctionEvent::Run() /builds/worker/workspace/obj-build/dist/include/mozilla/net/ChannelEventQueue.h:79:25 (libxul.so+0x1037543)
[task 2020-05-30T06:08:48.387Z] 06:08:48 INFO - GECKO(2302) | #26 mozilla::net::ChannelEventQueue::RunOrEnqueue(mozilla::net::ChannelEvent*, bool) /builds/worker/workspace/obj-build/dist/include/mozilla/net/ChannelEventQueue.h:260:10 (libxul.so+0x101fcd7)
[task 2020-05-30T06:08:48.387Z] 06:08:48 INFO - GECKO(2302) | #27 mozilla::net::HttpChannelChild::RecvOnStartRequest(mozilla::net::nsHttpResponseHead const&, bool const&, mozilla::net::nsHttpHeaderArray const&, mozilla::net::HttpChannelOnStartRequestArgs const&) /builds/worker/checkouts/gecko/netwerk/protocol/http/HttpChannelChild.cpp:408:12 (libxul.so+0x10c6473)
[task 2020-05-30T06:08:48.387Z] 06:08:48 INFO - GECKO(2302) | #28 mozilla::net::PHttpChannelChild::OnMessageReceived(IPC::Message const&) /builds/worker/workspace/obj-build/ipc/ipdl/PHttpChannelChild.cpp:636:28 (libxul.so+0x15b0b8b)
[task 2020-05-30T06:08:48.388Z] 06:08:48 INFO - GECKO(2302) | #29 mozilla::dom::PContentChild::OnMessageReceived(IPC::Message const&) /builds/worker/workspace/obj-build/ipc/ipdl/PContentChild.cpp:8150:32 (libxul.so+0x14c13b7)
[task 2020-05-30T06:08:48.388Z] 06:08:48 INFO - GECKO(2302) | #30 mozilla::dom::ContentChild::OnMessageReceived(IPC::Message const&) /builds/worker/checkouts/gecko/dom/ipc/ContentChild.cpp:3543:25 (libxul.so+0x437dfe0)
[task 2020-05-30T06:08:48.388Z] 06:08:48 INFO - GECKO(2302) | #31 mozilla::ipc::MessageChannel::DispatchAsyncMessage(mozilla::ipc::ActorLifecycleProxy*, IPC::Message const&) /builds/worker/checkouts/gecko/ipc/glue/MessageChannel.cpp:2190:25 (libxul.so+0x13c5316)
[task 2020-05-30T06:08:48.388Z] 06:08:48 INFO - GECKO(2302) | #32 mozilla::ipc::MessageChannel::DispatchMessage(IPC::Message&&) /builds/worker/checkouts/gecko/ipc/glue/MessageChannel.cpp:2114:9 (libxul.so+0x13c37fd)
[task 2020-05-30T06:08:48.389Z] 06:08:48 INFO - GECKO(2302) | #33 mozilla::ipc::MessageChannel::RunMessage(mozilla::ipc::MessageChannel::MessageTask&) /builds/worker/checkouts/gecko/ipc/glue/MessageChannel.cpp:1962:3 (libxul.so+0x13c4371)
[task 2020-05-30T06:08:48.389Z] 06:08:48 INFO - GECKO(2302) | #34 mozilla::ipc::MessageChannel::MessageTask::Run() /builds/worker/checkouts/gecko/ipc/glue/MessageChannel.cpp:1993:13 (libxul.so+0x13c48a9)
[task 2020-05-30T06:08:48.389Z] 06:08:48 INFO - GECKO(2302) | #35 nsThread::ProcessNextEvent(bool, bool*) /builds/worker/checkouts/gecko/xpcom/threads/nsThread.cpp:1211:14 (libxul.so+0xb04018)
[task 2020-05-30T06:08:48.389Z] 06:08:48 INFO - GECKO(2302) | #36 NS_ProcessNextEvent(nsIThread*, bool) /builds/worker/checkouts/gecko/xpcom/threads/nsThreadUtils.cpp:501:10 (libxul.so+0xb08a12)
[task 2020-05-30T06:08:48.390Z] 06:08:48 INFO - GECKO(2302) | #37 mozilla::ipc::MessagePump::Run(base::MessagePump::Delegate*) /builds/worker/checkouts/gecko/ipc/glue/MessagePump.cpp:109:5 (libxul.so+0x13c8e2e)
[task 2020-05-30T06:08:48.390Z] 06:08:48 INFO - GECKO(2302) | #38 mozilla::ipc::MessagePumpForChildProcess::Run(base::MessagePump::Delegate*) /builds/worker/checkouts/gecko/ipc/glue/MessagePump.cpp:270:30 (libxul.so+0x13c978b)
[task 2020-05-30T06:08:48.390Z] 06:08:48 INFO - GECKO(2302) | #39 RunInternal /builds/worker/checkouts/gecko/ipc/chromium/src/base/message_loop.cc:315:10 (libxul.so+0x1355bec)
[task 2020-05-30T06:08:48.391Z] 06:08:48 INFO - GECKO(2302) | #40 RunHandler /builds/worker/checkouts/gecko/ipc/chromium/src/base/message_loop.cc:308:3 (libxul.so+0x1355bec)
[task 2020-05-30T06:08:48.391Z] 06:08:48 INFO - GECKO(2302) | #41 MessageLoop::Run() /builds/worker/checkouts/gecko/ipc/chromium/src/base/message_loop.cc:290:3 (libxul.so+0x1355bec)
[task 2020-05-30T06:08:48.391Z] 06:08:48 INFO - GECKO(2302) | #42 nsBaseAppShell::Run() /builds/worker/checkouts/gecko/widget/nsBaseAppShell.cpp:137:27 (libxul.so+0x481aa23)
[task 2020-05-30T06:08:48.391Z] 06:08:48 INFO - GECKO(2302) | #43 XRE_RunAppShell() /builds/worker/checkouts/gecko/toolkit/xre/nsEmbedFunctions.cpp:913:20 (libxul.so+0x6421a79)
[task 2020-05-30T06:08:48.392Z] 06:08:48 INFO - GECKO(2302) | #44 mozilla::ipc::MessagePumpForChildProcess::Run(base::MessagePump::Delegate*) /builds/worker/checkouts/gecko/ipc/glue/MessagePump.cpp:237:9 (libxul.so+0x13c973a)
[task 2020-05-30T06:08:48.392Z] 06:08:48 INFO - GECKO(2302) | #45 RunInternal /builds/worker/checkouts/gecko/ipc/chromium/src/base/message_loop.cc:315:10 (libxul.so+0x1355bec)
[task 2020-05-30T06:08:48.392Z] 06:08:48 INFO - GECKO(2302) | #46 RunHandler /builds/worker/checkouts/gecko/ipc/chromium/src/base/message_loop.cc:308:3 (libxul.so+0x1355bec)
[task 2020-05-30T06:08:48.392Z] 06:08:48 INFO - GECKO(2302) | #47 MessageLoop::Run() /builds/worker/checkouts/gecko/ipc/chromium/src/base/message_loop.cc:290:3 (libxul.so+0x1355bec)
[task 2020-05-30T06:08:48.393Z] 06:08:48 INFO - GECKO(2302) | #48 XRE_InitChildProcess(int, char**, XREChildData const*) /builds/worker/checkouts/gecko/toolkit/xre/nsEmbedFunctions.cpp:744:34 (libxul.so+0x64217f9)
[task 2020-05-30T06:08:48.393Z] 06:08:48 INFO - GECKO(2302) | #49 mozilla::BootstrapImpl::XRE_InitChildProcess(int, char**, XREChildData const*) /builds/worker/checkouts/gecko/toolkit/xre/Bootstrap.cpp:67:12 (libxul.so+0x64298c2)
[task 2020-05-30T06:08:48.393Z] 06:08:48 INFO - GECKO(2302) | #50 content_process_main /builds/worker/checkouts/gecko/browser/app/../../ipc/contentproc/plugin-container.cpp:56:28 (firefox+0xca0c7)
[task 2020-05-30T06:08:48.393Z] 06:08:48 INFO - GECKO(2302) | #51 main /builds/worker/checkouts/gecko/browser/app/nsBrowserApp.cpp:303:18 (firefox+0xca0c7)
[task 2020-05-30T06:08:48.394Z] 06:08:48 INFO - GECKO(2302) | SUMMARY: ThreadSanitizer: data race /builds/worker/checkouts/gecko/parser/html/nsHtml5StreamParserPtr.h:42:13 in assign_assuming_AddRef
[task 2020-05-30T06:08:48.394Z] 06:08:48 INFO - GECKO(2302) | ==================
[task 2020-05-30T06:08:48.740Z] 06:08:48 ERROR - GECKO(2302) | A content process crashed and MOZ_CRASHREPORTER_SHUTDOWN is set, shutting down
[task 2020-05-30T06:08:51.258Z] 06:08:51 INFO - GECKO(2302) | 1590818931252 Marionette TRACE Received observer notification xpcom-will-shutdown
[task 2020-05-30T06:08:51.259Z] 06:08:51 INFO - GECKO(2302) | 1590818931253 Marionette INFO Stopped listening on port 2828
[task 2020-05-30T06:08:51.260Z] 06:08:51 INFO - GECKO(2302) | 1590818931253 Marionette DEBUG Marionette stopped listening
[task 2020-05-30T06:08:59.805Z] 06:08:59 INFO - GECKO(2302) | [2020-05-30T06:08:59Z ERROR xulstore::persist] removeDocument error: unavailable
[task 2020-05-30T06:09:01.016Z] 06:09:01 INFO - TEST-INFO | Main app process: exit 0
[task 2020-05-30T06:09:01.016Z] 06:09:01 INFO - runtests.py | Application ran for: 0:01:29.151053
[task 2020-05-30T06:09:01.017Z] 06:09:01 INFO - zombiecheck | Reading PID log: /tmp/tmpbvLBLipidlog
[task 2020-05-30T06:09:01.018Z] 06:09:01 INFO - ==> process 2302 launched child process 2317
[task 2020-05-30T06:09:01.018Z] 06:09:01 INFO - ==> process 2302 launched child process 2420
[task 2020-05-30T06:09:01.018Z] 06:09:01 INFO - ==> process 2302 launched child process 2436
[task 2020-05-30T06:09:01.019Z] 06:09:01 INFO - ==> process 2302 launched child process 2504
[task 2020-05-30T06:09:01.019Z] 06:09:01 INFO - ==> process 2302 launched child process 2528
[task 2020-05-30T06:09:01.019Z] 06:09:01 INFO - zombiecheck | Checking for orphan process with PID: 2504
[task 2020-05-30T06:09:01.020Z] 06:09:01 INFO - zombiecheck | Checking for orphan process with PID: 2436
[task 2020-05-30T06:09:01.020Z] 06:09:01 INFO - zombiecheck | Checking for orphan process with PID: 2528
[task 2020-05-30T06:09:01.021Z] 06:09:01 INFO - zombiecheck | Checking for orphan process with PID: 2420
[task 2020-05-30T06:09:01.021Z] 06:09:01 INFO - zombiecheck | Checking for orphan process with PID: 2317
[task 2020-05-30T06:09:01.021Z] 06:09:01 INFO - Stopping web server
[task 2020-05-30T06:09:01.042Z] 06:09:01 INFO - Stopping web socket server
[task 2020-05-30T06:09:01.062Z] 06:09:01 INFO - Stopping ssltunnel
[task 2020-05-30T06:09:01.083Z] 06:09:01 WARNING - leakcheck | refcount logging is off, so leaks can't be detected!
[task 2020-05-30T06:09:01.083Z] 06:09:01 INFO - runtests.py | Running tests: end.
[task 2020-05-30T06:09:01.103Z] 06:09:01 INFO - Buffered messages logged at 06:08:19
[task 2020-05-30T06:09:01.104Z] 06:09:01 INFO - TEST-PASS | dom/tests/mochitest/bugs/test_bug260264.html | A valid string reason is expected
[task 2020-05-30T06:09:01.104Z] 06:09:01 INFO - TEST-PASS | dom/tests/mochitest/bugs/test_bug260264.html | Reason cannot be empty
[task 2020-05-30T06:09:01.104Z] 06:09:01 INFO - add_task | Entering test check_sanity
[task 2020-05-30T06:09:01.105Z] 06:09:01 INFO - Buffered messages logged at 06:08:20
[task 2020-05-30T06:09:01.105Z] 06:09:01 INFO - TEST-FAIL | dom/tests/mochitest/bugs/test_bug260264.html | The author of the test has indicated that flaky timeouts are expected. Reason: untriaged
[task 2020-05-30T06:09:01.105Z] 06:09:01 INFO - TEST-PASS | dom/tests/mochitest/bugs/test_bug260264.html | popup value should have UNKNOWN permission
[task 2020-05-30T06:09:01.105Z] 06:09:01 INFO - TEST-PASS | dom/tests/mochitest/bugs/test_bug260264.html | popup value should have ALLOW permission
[task 2020-05-30T06:09:01.109Z] 06:09:01 INFO - add_task | Leaving test check_sanity
[task 2020-05-30T06:09:01.109Z] 06:09:01 INFO - add_task | Entering test run_tests
[task 2020-05-30T06:09:01.109Z] 06:09:01 INFO - TEST-PASS | dom/tests/mochitest/bugs/test_bug260264.html | not properly opened
[task 2020-05-30T06:09:01.110Z] 06:09:01 INFO - Buffered messages logged at 06:08:21
[task 2020-05-30T06:09:01.110Z] 06:09:01 INFO - TEST-PASS | dom/tests/mochitest/bugs/test_bug260264.html | not properly opened
[task 2020-05-30T06:09:01.111Z] 06:09:01 INFO - TEST-PASS | dom/tests/mochitest/bugs/test_bug260264.html | not properly opened
[task 2020-05-30T06:09:01.112Z] 06:09:01 INFO - Buffered messages logged at 06:08:22
[task 2020-05-30T06:09:01.112Z] 06:09:01 INFO - TEST-PASS | dom/tests/mochitest/bugs/test_bug260264.html | not properly opened
[task 2020-05-30T06:09:01.112Z] 06:09:01 INFO - Buffered messages logged at 06:08:23
[task 2020-05-30T06:09:01.112Z] 06:09:01 INFO - add_task | Leaving test run_tests
[task 2020-05-30T06:09:01.113Z] 06:09:01 INFO - add_task | Entering test run_tests2
[task 2020-05-30T06:09:01.114Z] 06:09:01 INFO - Buffered messages logged at 06:08:24
[task 2020-05-30T06:09:01.114Z] 06:09:01 INFO - TEST-PASS | dom/tests/mochitest/bugs/test_bug260264.html | not properly blocked
Description
•