Closed Bug 1637878 Opened 1 year ago Closed 5 months ago

Intermittent SUMMARY: ThreadSanitizer: lock-order-inversion (potential deadlock) /builds/worker/checkouts/gecko/mozglue/misc/Mutex_posix.cpp:118:3 in mutexLock

Categories

(Core :: mozglue, defect, P5)

defect

Tracking

()

RESOLVED DUPLICATE of bug 1608462

People

(Reporter: intermittent-bug-filer, Unassigned)

References

(Blocks 1 open bug)

Details

(Keywords: intermittent-failure)

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


[task 2020-05-14T07:40:49.689Z] 07:40:49     INFO -  TEST-START | netwerk/test/unit/test_tls_server.js
[task 2020-05-14T07:40:51.797Z] 07:40:51  WARNING -  TEST-UNEXPECTED-FAIL | netwerk/test/unit/test_tls_server.js | xpcshell return code: -6
[task 2020-05-14T07:40:51.798Z] 07:40:51     INFO -  TEST-INFO took 2104ms
[task 2020-05-14T07:40:51.799Z] 07:40:51     INFO -  >>>>>>>
[task 2020-05-14T07:40:51.800Z] 07:40:51     INFO -  TEST-PASS | netwerk/test/unit/test_tls_server.js | undefined assertion name - true == true
[task 2020-05-14T07:40:51.801Z] 07:40:51     INFO -  (xpcshell/head.js) | test MAIN run_test pending (1)
[task 2020-05-14T07:40:51.801Z] 07:40:51     INFO -  (xpcshell/head.js) | test run_next_test 0 pending (2)
[task 2020-05-14T07:40:51.802Z] 07:40:51     INFO -  (xpcshell/head.js) | test MAIN run_test finished (2)
[task 2020-05-14T07:40:51.803Z] 07:40:51     INFO -  running event loop
[task 2020-05-14T07:40:51.803Z] 07:40:51     INFO -  netwerk/test/unit/test_tls_server.js | Starting
[task 2020-05-14T07:40:51.803Z] 07:40:51     INFO -  (xpcshell/head.js) | test pending (2)
[task 2020-05-14T07:40:51.805Z] 07:40:51     INFO -  (xpcshell/head.js) | test run_next_test 0 finished (2)
[task 2020-05-14T07:40:51.805Z] 07:40:51     INFO -  TEST-PASS | netwerk/test/unit/test_tls_server.js |  - Got self-signed cert - true == true
[task 2020-05-14T07:40:51.805Z] 07:40:51     INFO -  "Accept TLS client connection"
[task 2020-05-14T07:40:51.805Z] 07:40:51     INFO -  "Output to server written"
[task 2020-05-14T07:40:51.805Z] 07:40:51     INFO -  "TLS handshake done"
[task 2020-05-14T07:40:51.808Z] 07:40:51     INFO -  TEST-PASS | netwerk/test/unit/test_tls_server.js |  - Has peer cert - true == true
[task 2020-05-14T07:40:51.808Z] 07:40:51     INFO -  TEST-PASS | netwerk/test/unit/test_tls_server.js |  - Peer cert matches expected cert - true == true
[task 2020-05-14T07:40:51.809Z] 07:40:51     INFO -  TEST-PASS | netwerk/test/unit/test_tls_server.js |  - Using TLS 1.2 - 771 == 771
[task 2020-05-14T07:40:51.809Z] 07:40:51     INFO -  TEST-PASS | netwerk/test/unit/test_tls_server.js |  - Using expected cipher - "TLS_ECDHE_ECDSA_WITH_AES_128_GCM_SHA256" == "TLS_ECDHE_ECDSA_WITH_AES_128_GCM_SHA256"
[task 2020-05-14T07:40:51.809Z] 07:40:51     INFO -  TEST-PASS | netwerk/test/unit/test_tls_server.js |  - Using 128-bit key - 128 == 128
[task 2020-05-14T07:40:51.809Z] 07:40:51     INFO -  TEST-PASS | netwerk/test/unit/test_tls_server.js |  - Using 128-bit MAC - 128 == 128
[task 2020-05-14T07:40:51.809Z] 07:40:51     INFO -  TEST-PASS | netwerk/test/unit/test_tls_server.js |  - Echoed data received - "HELLO" == "HELLO"
[task 2020-05-14T07:40:51.810Z] 07:40:51     INFO -  TEST-PASS | netwerk/test/unit/test_tls_server.js |  - No cert alert expected - true == true
[task 2020-05-14T07:40:51.811Z] 07:40:51     INFO -  PID 18915 | ==================
[task 2020-05-14T07:40:51.811Z] 07:40:51     INFO -  PID 18915 | WARNING: ThreadSanitizer: lock-order-inversion (potential deadlock) (pid=18915)
[task 2020-05-14T07:40:51.811Z] 07:40:51     INFO -  PID 18915 |   Cycle in lock order graph: M16450 (0x7b2c00005c20) => M1151368289813848592 (0x000000000000) => M16450
[task 2020-05-14T07:40:51.812Z] 07:40:51     INFO -  PID 18915 |   Mutex M1151368289813848592 acquired here while holding mutex M16450 in thread T4:
[task 2020-05-14T07:40:51.812Z] 07:40:51     INFO -  PID 18915 |     #0 pthread_mutex_lock /builds/worker/fetches/llvm-project/llvm/projects/compiler-rt/lib/tsan/../sanitizer_common/sanitizer_common_interceptors.inc:4139:3 (xpcshell+0x75596)
[task 2020-05-14T07:40:51.813Z] 07:40:51     INFO -  PID 18915 |     #1 mutexLock /builds/worker/checkouts/gecko/mozglue/misc/Mutex_posix.cpp:118:3 (xpcshell+0x1285d8)
[task 2020-05-14T07:40:51.813Z] 07:40:51     INFO -  PID 18915 |     #2 mozilla::detail::MutexImpl::lock() /builds/worker/checkouts/gecko/mozglue/misc/Mutex_posix.cpp:142:3 (xpcshell+0x1285d8)
[task 2020-05-14T07:40:51.813Z] 07:40:51     INFO -  PID 18915 |     #3 Lock /builds/worker/workspace/obj-build/dist/include/mozilla/Mutex.h:63:23 (libxul.so+0xc8eb35)
[task 2020-05-14T07:40:51.813Z] 07:40:51     INFO -  PID 18915 |     #4 BaseAutoLock /builds/worker/workspace/obj-build/dist/include/mozilla/Mutex.h:161:11 (libxul.so+0xc8eb35)
[task 2020-05-14T07:40:51.813Z] 07:40:51     INFO -  PID 18915 |     #5 mozilla::net::nsSocketOutputStream::Write(char const*, unsigned int, unsigned int*) /builds/worker/checkouts/gecko/netwerk/base/nsSocketTransport2.cpp:555:19 (libxul.so+0xc8eb35)
[task 2020-05-14T07:40:51.814Z] 07:40:51     INFO -  PID 18915 |     #6 nsStreamCopierIB::ConsumeInputBuffer(nsIInputStream*, void*, char const*, unsigned int, unsigned int, unsigned int*) /builds/worker/checkouts/gecko/xpcom/io/nsStreamUtils.cpp:501:33 (libxul.so+0xabe823)
[task 2020-05-14T07:40:51.814Z] 07:40:51     INFO -  PID 18915 |     #7 nsPipeInputStream::ReadSegments(nsresult (*)(nsIInputStream*, void*, char const*, unsigned int, unsigned int, unsigned int*), void*, unsigned int, unsigned int*) /builds/worker/checkouts/gecko/xpcom/io/nsPipe3.cpp:1346:12 (libxul.so+0xaaf883)
[task 2020-05-14T07:40:51.814Z] 07:40:51     INFO -  PID 18915 |     #8 nsStreamCopierIB::DoCopy(nsresult*, nsresult*) /builds/worker/checkouts/gecko/xpcom/io/nsStreamUtils.cpp:519:18 (libxul.so+0xabe1ae)
[task 2020-05-14T07:40:51.814Z] 07:40:51     INFO -  PID 18915 |     #9 nsAStreamCopier::Process() /builds/worker/checkouts/gecko/xpcom/io/nsStreamUtils.cpp:302:22 (libxul.so+0xabf01b)
[task 2020-05-14T07:40:51.815Z] 07:40:51     INFO -  PID 18915 |     #10 Run /builds/worker/checkouts/gecko/xpcom/io/nsStreamUtils.cpp:418:5 (libxul.so+0xabcf21)
[task 2020-05-14T07:40:51.815Z] 07:40:51     INFO -  PID 18915 |     #11 non-virtual thunk to nsAStreamCopier::Run() /builds/worker/checkouts/gecko/xpcom/io/nsStreamUtils.cpp (libxul.so+0xabcf21)
[task 2020-05-14T07:40:51.816Z] 07:40:51     INFO -  PID 18915 |     #12 nsThread::ProcessNextEvent(bool, bool*) /builds/worker/checkouts/gecko/xpcom/threads/nsThread.cpp:1211:14 (libxul.so+0xafe758)
[task 2020-05-14T07:40:51.816Z] 07:40:51     INFO -  PID 18915 |     #13 NS_ProcessNextEvent(nsIThread*, bool) /builds/worker/checkouts/gecko/xpcom/threads/nsThreadUtils.cpp:501:10 (libxul.so+0xb03152)
[task 2020-05-14T07:40:51.824Z] 07:40:51     INFO -  PID 18915 |     #14 nsComponentManagerImpl::GetServiceLocked((anonymous namespace)::MutexLock&, (anonymous namespace)::EntryWrapper&, nsID const&, void**) /builds/worker/checkouts/gecko/xpcom/components/nsComponentManager.cpp:1339:10 (libxul.so+0xad7390)
[task 2020-05-14T07:40:51.825Z] 07:40:51     INFO -  PID 18915 |     #15 nsComponentManagerImpl::GetService(nsID const&, nsID const&, void**) /builds/worker/checkouts/gecko/xpcom/components/nsComponentManager.cpp:1424:10 (libxul.so+0xad2498)
[task 2020-05-14T07:40:51.826Z] 07:40:51     INFO -  PID 18915 |     #16 CallGetService /builds/worker/checkouts/gecko/xpcom/components/nsComponentManagerUtils.cpp:51:43 (libxul.so+0xada8cb)
[task 2020-05-14T07:40:51.827Z] 07:40:51     INFO -  PID 18915 |     #17 nsGetServiceByCID::operator()(nsID const&, void**) const /builds/worker/checkouts/gecko/xpcom/components/nsComponentManagerUtils.cpp:220:21 (libxul.so+0xada8cb)
[task 2020-05-14T07:40:51.828Z] 07:40:51     INFO -  PID 18915 |     #18 nsCOMPtr_base::assign_from_gs_cid(nsGetServiceByCID, nsID const&) /builds/worker/checkouts/gecko/xpcom/base/nsCOMPtr.cpp:64:7 (libxul.so+0xa21f30)
[task 2020-05-14T07:40:51.829Z] 07:40:51     INFO -  PID 18915 |     #19 nsCOMPtr /builds/worker/workspace/obj-build/dist/include/nsCOMPtr.h:599:5 (libxul.so+0x61c036a)
[task 2020-05-14T07:40:51.830Z] 07:40:51     INFO -  PID 18915 |     #20 ClientAuthCertNonverifyingTrustDomain /builds/worker/checkouts/gecko/security/manager/ssl/nsNSSIOLayer.cpp:1973:9 (libxul.so+0x61c036a)
[task 2020-05-14T07:40:51.830Z] 07:40:51     INFO -  PID 18915 |     #21 ClientAuthDataRunnable::BuildChainForCertificate(CERTCertificateStr*, std::unique_ptr<CERTCertListStr, mozilla::UniqueCERTCertListDeletePolicy>&) /builds/worker/checkouts/gecko/security/manager/ssl/nsNSSIOLayer.cpp:2195:41 (libxul.so+0x61c036a)
[task 2020-05-14T07:40:51.831Z] 07:40:51     INFO -  PID 18915 |     #22 DoGetClientAuthData(ClientAuthInfo&&, std::unique_ptr<CERTCertificateStr, mozilla::UniqueCERTCertificateDeletePolicy> const&, nsTArray<nsTArray<unsigned char> >&&, std::unique_ptr<CERTCertificateStr, mozilla::UniqueCERTCertificateDeletePolicy>&, std::unique_ptr<SECKEYPrivateKeyStr, mozilla::UniqueSECKEYPrivateKeyDeletePolicy>&, std::unique_ptr<CERTCertListStr, mozilla::UniqueCERTCertListDeletePolicy>&) /builds/worker/checkouts/gecko/security/manager/ssl/nsNSSIOLayer.cpp:1952:19 (libxul.so+0x61bf830)
[task 2020-05-14T07:40:51.831Z] 07:40:51     INFO -  PID 18915 |     #23 nsNSS_SSLGetClientAuthData(void*, PRFileDesc*, CERTDistNamesStr*, CERTCertificateStr**, SECKEYPrivateKeyStr**) /builds/worker/checkouts/gecko/security/manager/ssl/nsNSSIOLayer.cpp:1902:22 (libxul.so+0x61bed73)
[task 2020-05-14T07:40:51.832Z] 07:40:51     INFO -  PID 18915 |     #24 ssl3_CompleteHandleCertificateRequest /builds/worker/checkouts/gecko/security/nss/lib/ssl/ssl3con.c:7616:25 (libssl3.so+0x1cf99)
[task 2020-05-14T07:40:51.832Z] 07:40:51     INFO -  PID 18915 |     #25 ssl3_HandleCertificateRequest /builds/worker/checkouts/gecko/security/nss/lib/ssl/ssl3con.c:7573:10 (libssl3.so+0x248db)
[task 2020-05-14T07:40:51.832Z] 07:40:51     INFO -  PID 18915 |     #26 ssl3_HandlePostHelloHandshakeMessage /builds/worker/checkouts/gecko/security/nss/lib/ssl/ssl3con.c:12133:18 (libssl3.so+0x248db)
[task 2020-05-14T07:40:51.833Z] 07:40:51     INFO -  PID 18915 |     #27 ssl3_HandleHandshakeMessage /builds/worker/checkouts/gecko/security/nss/lib/ssl/ssl3con.c:12057:22 (libssl3.so+0x248db)
[task 2020-05-14T07:40:51.833Z] 07:40:51     INFO -  PID 18915 |     #28 ssl3_HandleHandshake /builds/worker/checkouts/gecko/security/nss/lib/ssl/ssl3con.c:12231:18 (libssl3.so+0x2648d)
[task 2020-05-14T07:40:51.833Z] 07:40:51     INFO -  PID 18915 |     #29 ssl3_HandleNonApplicationData /builds/worker/checkouts/gecko/security/nss/lib/ssl/ssl3con.c:12756:22 (libssl3.so+0x2648d)
[task 2020-05-14T07:40:51.834Z] 07:40:51     INFO -  PID 18915 |     #30 ssl3_HandleRecord /builds/worker/checkouts/gecko/security/nss/lib/ssl/ssl3con.c:13047:12 (libssl3.so+0x272c5)
[task 2020-05-14T07:40:51.834Z] 07:40:51     INFO -  PID 18915 |     #31 ssl3_GatherCompleteHandshake /builds/worker/checkouts/gecko/security/nss/lib/ssl/ssl3gthr.c:523:18 (libssl3.so+0x35bbf)
[task 2020-05-14T07:40:51.834Z] 07:40:51     INFO -  PID 18915 |     #32 ssl_GatherRecord1stHandshake /builds/worker/checkouts/gecko/security/nss/lib/ssl/sslcon.c:73:10 (libssl3.so+0x38da4)
[task 2020-05-14T07:40:51.835Z] 07:40:51     INFO -  PID 18915 |     #33 ssl_Do1stHandshake /builds/worker/checkouts/gecko/security/nss/lib/ssl/sslsecur.c:41:14 (libssl3.so+0x40fa4)
[task 2020-05-14T07:40:51.835Z] 07:40:51     INFO -  PID 18915 |     #34 ssl_SecureRecv /builds/worker/checkouts/gecko/security/nss/lib/ssl/sslsecur.c:808:18 (libssl3.so+0x40fa4)
[task 2020-05-14T07:40:51.835Z] 07:40:51     INFO -  PID 18915 |     #35 ssl_Recv /builds/worker/checkouts/gecko/security/nss/lib/ssl/sslsock.c:3105:10 (libssl3.so+0x50e10)
[task 2020-05-14T07:40:51.836Z] 07:40:51     INFO -  PID 18915 |     #36 PSMRecv(PRFileDesc*, void*, int, int, unsigned int) /builds/worker/checkouts/gecko/security/manager/ssl/nsNSSIOLayer.cpp:1242:7 (libxul.so+0x61bbb54)
[task 2020-05-14T07:40:51.836Z] 07:40:51     INFO -  PID 18915 |     #37 nsSSLIOLayerRead(PRFileDesc*, void*, int) /builds/worker/checkouts/gecko/security/manager/ssl/nsNSSIOLayer.cpp:1348:10 (libxul.so+0x61bc6ac)
[task 2020-05-14T07:40:51.836Z] 07:40:51     INFO -  PID 18915 |     #38 PR_Read /builds/worker/checkouts/gecko/nsprpub/pr/src/io/priometh.c:109:12 (libnspr4.so+0xdcca)
[task 2020-05-14T07:40:51.836Z] 07:40:51     INFO -  PID 18915 |     #39 mozilla::net::nsSocketInputStream::Read(char*, unsigned int, unsigned int*) /builds/worker/checkouts/gecko/netwerk/base/nsSocketTransport2.cpp:381:15 (libxul.so+0xc8ddc0)
[task 2020-05-14T07:40:51.837Z] 07:40:51     INFO -  PID 18915 |     #40 nsStreamCopierOB::FillOutputBuffer(nsIOutputStream*, void*, char*, unsigned int, unsigned int, unsigned int*) /builds/worker/checkouts/gecko/xpcom/io/nsStreamUtils.cpp:543:35 (libxul.so+0xabee33)
[task 2020-05-14T07:40:51.837Z] 07:40:51     INFO -  PID 18915 |     #41 nsPipeOutputStream::WriteSegments(nsresult (*)(nsIOutputStream*, void*, char*, unsigned int, unsigned int, unsigned int*), void*, unsigned int, unsigned int*) /builds/worker/checkouts/gecko/xpcom/io/nsPipe3.cpp:1684:12 (libxul.so+0xab1f60)
[task 2020-05-14T07:40:51.838Z] 07:40:51     INFO -  PID 18915 |     #42 nsStreamCopierOB::DoCopy(nsresult*, nsresult*) /builds/worker/checkouts/gecko/xpcom/io/nsStreamUtils.cpp:561:16 (libxul.so+0xabe90e)
[task 2020-05-14T07:40:51.838Z] 07:40:51     INFO -  PID 18915 |     #43 nsAStreamCopier::Process() /builds/worker/checkouts/gecko/xpcom/io/nsStreamUtils.cpp:302:22 (libxul.so+0xabf01b)
[task 2020-05-14T07:40:51.838Z] 07:40:51     INFO -  PID 18915 |     #44 Run /builds/worker/checkouts/gecko/xpcom/io/nsStreamUtils.cpp:418:5 (libxul.so+0xabcf21)
[task 2020-05-14T07:40:51.838Z] 07:40:51     INFO -  PID 18915 |     #45 non-virtual thunk to nsAStreamCopier::Run() /builds/worker/checkouts/gecko/xpcom/io/nsStreamUtils.cpp (libxul.so+0xabcf21)
[task 2020-05-14T07:40:51.839Z] 07:40:51     INFO -  PID 18915 |     #46 nsThread::ProcessNextEvent(bool, bool*) /builds/worker/checkouts/gecko/xpcom/threads/nsThread.cpp:1211:14 (libxul.so+0xafe758)
[task 2020-05-14T07:40:51.839Z] 07:40:51     INFO -  PID 18915 |     #47 NS_ProcessNextEvent(nsIThread*, bool) /builds/worker/checkouts/gecko/xpcom/threads/nsThreadUtils.cpp:501:10 (libxul.so+0xb03152)
[task 2020-05-14T07:40:51.839Z] 07:40:51     INFO -  PID 18915 |     #48 mozilla::net::nsSocketTransportService::Run() /builds/worker/checkouts/gecko/netwerk/base/nsSocketTransportService2.cpp:1134:11 (libxul.so+0xca0f38)
[task 2020-05-14T07:40:51.840Z] 07:40:51     INFO -  PID 18915 |     #49 non-virtual thunk to mozilla::net::nsSocketTransportService::Run() /builds/worker/checkouts/gecko/netwerk/base/nsSocketTransportService2.cpp (libxul.so+0xca23d9)
[task 2020-05-14T07:40:51.840Z] 07:40:51     INFO -  PID 18915 |     #50 nsThread::ProcessNextEvent(bool, bool*) /builds/worker/checkouts/gecko/xpcom/threads/nsThread.cpp:1211:14 (libxul.so+0xafe758)
[task 2020-05-14T07:40:51.841Z] 07:40:51     INFO -  PID 18915 |     #51 NS_ProcessNextEvent(nsIThread*, bool) /builds/worker/checkouts/gecko/xpcom/threads/nsThreadUtils.cpp:501:10 (libxul.so+0xb03152)
[task 2020-05-14T07:40:51.841Z] 07:40:51     INFO -  PID 18915 |     #52 mozilla::ipc::MessagePumpForNonMainThreads::Run(base::MessagePump::Delegate*) /builds/worker/checkouts/gecko/ipc/glue/MessagePump.cpp:302:20 (libxul.so+0x13b1d2e)
[task 2020-05-14T07:40:51.842Z] 07:40:51     INFO -  PID 18915 |     #53 RunInternal /builds/worker/checkouts/gecko/ipc/chromium/src/base/message_loop.cc:315:10 (libxul.so+0x134104c)
[task 2020-05-14T07:40:51.842Z] 07:40:51     INFO -  PID 18915 |     #54 RunHandler /builds/worker/checkouts/gecko/ipc/chromium/src/base/message_loop.cc:308:3 (libxul.so+0x134104c)
[task 2020-05-14T07:40:51.843Z] 07:40:51     INFO -  PID 18915 |     #55 MessageLoop::Run() /builds/worker/checkouts/gecko/ipc/chromium/src/base/message_loop.cc:290:3 (libxul.so+0x134104c)
[task 2020-05-14T07:40:51.843Z] 07:40:51     INFO -  PID 18915 |     #56 nsThread::ThreadFunc(void*) /builds/worker/checkouts/gecko/xpcom/threads/nsThread.cpp:444:10 (libxul.so+0xafad75)
[task 2020-05-14T07:40:51.843Z] 07:40:51     INFO -  PID 18915 |     #57 _pt_root /builds/worker/checkouts/gecko/nsprpub/pr/src/pthreads/ptthread.c:201:5 (libnspr4.so+0x44d8f)
[task 2020-05-14T07:40:51.844Z] 07:40:51     INFO -  PID 18915 |     Hint: use TSAN_OPTIONS=second_deadlock_stack=1 to get more informative warning message
[task 2020-05-14T07:40:51.844Z] 07:40:51     INFO -  PID 18915 |   Mutex M16450 acquired here while holding mutex M1151368289813848592 in thread T4:
[task 2020-05-14T07:40:51.845Z] 07:40:51     INFO -  PID 18915 |     #0 pthread_mutex_lock /builds/worker/fetches/llvm-project/llvm/projects/compiler-rt/lib/tsan/../sanitizer_common/sanitizer_common_interceptors.inc:4139:3 (xpcshell+0x75596)
[task 2020-05-14T07:40:51.845Z] 07:40:51     INFO -  PID 18915 |     #1 PR_Lock /builds/worker/checkouts/gecko/nsprpub/pr/src/pthreads/ptsynch.c:176:10 (libnspr4.so+0x2a2f8)
[task 2020-05-14T07:40:51.845Z] 07:40:51     INFO -  PID 18915 |     #2 ssl_Close /builds/worker/checkouts/gecko/security/nss/lib/ssl/sslsock.c:3075:5 (libssl3.so+0x4f498)
[task 2020-05-14T07:40:51.846Z] 07:40:51     INFO -  PID 18915 |     #3 nsNSSSocketInfo::CloseSocketAndDestroy() /builds/worker/checkouts/gecko/security/manager/ssl/nsNSSIOLayer.cpp:691:21 (libxul.so+0x61ba68e)
[task 2020-05-14T07:40:51.846Z] 07:40:51     INFO -  PID 18915 |     #4 nsSSLIOLayerClose(PRFileDesc*) /builds/worker/checkouts/gecko/security/manager/ssl/nsNSSIOLayer.cpp:663:22 (libxul.so+0x61bc5cf)
[task 2020-05-14T07:40:51.847Z] 07:40:51     INFO -  PID 18915 |     #5 PR_Close /builds/worker/checkouts/gecko/nsprpub/pr/src/io/priometh.c:104:12 (libnspr4.so+0xdc7b)
[task 2020-05-14T07:40:51.847Z] 07:40:51     INFO -  PID 18915 |     #6 CloseSocket /builds/worker/checkouts/gecko/netwerk/base/nsSocketTransport2.cpp:3546:3 (libxul.so+0xc8d9f0)
[task 2020-05-14T07:40:51.847Z] 07:40:51     INFO -  PID 18915 |     #7 mozilla::net::nsSocketTransport::ReleaseFD_Locked(PRFileDesc*) /builds/worker/checkouts/gecko/netwerk/base/nsSocketTransport2.cpp:2095:9 (libxul.so+0xc8d9f0)
[task 2020-05-14T07:40:51.848Z] 07:40:51     INFO -  PID 18915 |     #8 mozilla::net::nsSocketTransport::OnSocketDetached(PRFileDesc*) /builds/worker/checkouts/gecko/netwerk/base/nsSocketTransport2.cpp:2487:7 (libxul.so+0xc9464c)
[task 2020-05-14T07:40:51.848Z] 07:40:51     INFO -  PID 18915 |     #9 mozilla::net::nsSocketTransportService::DetachSocket(mozilla::net::nsSocketTransportService::SocketContext*, mozilla::net::nsSocketTransportService::SocketContext*) /builds/worker/checkouts/gecko/netwerk/base/nsSocketTransportService2.cpp:420:21 (libxul.so+0xc9db21)
[task 2020-05-14T07:40:51.852Z] 07:40:51     INFO -  PID 18915 |     #10 mozilla::net::nsSocketTransportService::DoPollIteration(mozilla::BaseTimeDuration<mozilla::TimeDurationValueCalculator>*) /builds/worker/checkouts/gecko/netwerk/base/nsSocketTransportService2.cpp:1237:7 (libxul.so+0xca16ca)
[task 2020-05-14T07:40:51.852Z] 07:40:51     INFO -  PID 18915 |     #11 mozilla::net::nsSocketTransportService::Run() /builds/worker/checkouts/gecko/netwerk/base/nsSocketTransportService2.cpp:1094:7 (libxul.so+0xca0ccc)
[task 2020-05-14T07:40:51.852Z] 07:40:51     INFO -  PID 18915 |     #12 non-virtual thunk to mozilla::net::nsSocketTransportService::Run() /builds/worker/checkouts/gecko/netwerk/base/nsSocketTransportService2.cpp (libxul.so+0xca23d9)
[task 2020-05-14T07:40:51.852Z] 07:40:51     INFO -  PID 18915 |     #13 nsThread::ProcessNextEvent(bool, bool*) /builds/worker/checkouts/gecko/xpcom/threads/nsThread.cpp:1211:14 (libxul.so+0xafe758)
[task 2020-05-14T07:40:51.853Z] 07:40:51     INFO -  PID 18915 |     #14 NS_ProcessNextEvent(nsIThread*, bool) /builds/worker/checkouts/gecko/xpcom/threads/nsThreadUtils.cpp:501:10 (libxul.so+0xb03152)
[task 2020-05-14T07:40:51.853Z] 07:40:51     INFO -  PID 18915 |     #15 mozilla::ipc::MessagePumpForNonMainThreads::Run(base::MessagePump::Delegate*) /builds/worker/checkouts/gecko/ipc/glue/MessagePump.cpp:302:20 (libxul.so+0x13b1d2e)
[task 2020-05-14T07:40:51.853Z] 07:40:51     INFO -  PID 18915 |     #16 RunInternal /builds/worker/checkouts/gecko/ipc/chromium/src/base/message_loop.cc:315:10 (libxul.so+0x134104c)
[task 2020-05-14T07:40:51.853Z] 07:40:51     INFO -  PID 18915 |     #17 RunHandler /builds/worker/checkouts/gecko/ipc/chromium/src/base/message_loop.cc:308:3 (libxul.so+0x134104c)
[task 2020-05-14T07:40:51.854Z] 07:40:51     INFO -  PID 18915 |     #18 MessageLoop::Run() /builds/worker/checkouts/gecko/ipc/chromium/src/base/message_loop.cc:290:3 (libxul.so+0x134104c)
[task 2020-05-14T07:40:51.854Z] 07:40:51     INFO -  PID 18915 |     #19 nsThread::ThreadFunc(void*) /builds/worker/checkouts/gecko/xpcom/threads/nsThread.cpp:444:10 (libxul.so+0xafad75)
[task 2020-05-14T07:40:51.854Z] 07:40:51     INFO -  PID 18915 |     #20 _pt_root /builds/worker/checkouts/gecko/nsprpub/pr/src/pthreads/ptthread.c:201:5 (libnspr4.so+0x44d8f)
[task 2020-05-14T07:40:51.854Z] 07:40:51     INFO -  PID 18915 |   Thread T4 'Socket Thread' (tid=18920, running) created by main thread at:
[task 2020-05-14T07:40:51.855Z] 07:40:51     INFO -  PID 18915 |     #0 pthread_create /builds/worker/fetches/llvm-project/llvm/projects/compiler-rt/lib/tsan/rtl/tsan_interceptors.cc:967:3 (xpcshell+0x5747b)
[task 2020-05-14T07:40:51.855Z] 07:40:51     INFO -  PID 18915 |     #1 _PR_CreateThread /builds/worker/checkouts/gecko/nsprpub/pr/src/pthreads/ptthread.c:458:14 (libnspr4.so+0x3bf93)
[task 2020-05-14T07:40:51.855Z] 07:40:51     INFO -  PID 18915 |     #2 PR_CreateThread /builds/worker/checkouts/gecko/nsprpub/pr/src/pthreads/ptthread.c:533:12 (libnspr4.so+0x308c2)
[task 2020-05-14T07:40:51.855Z] 07:40:51     INFO -  PID 18915 |     #3 nsThread::Init(nsTSubstring<char> const&) /builds/worker/checkouts/gecko/xpcom/threads/nsThread.cpp:652:8 (libxul.so+0xafc20b)
[task 2020-05-14T07:40:51.855Z] 07:40:51     INFO -  PID 18915 |     #4 nsThreadManager::NewNamedThread(nsTSubstring<char> const&, unsigned int, nsIThread**) /builds/worker/checkouts/gecko/xpcom/threads/nsThreadManager.cpp:620:12 (libxul.so+0xb0289b)
[task 2020-05-14T07:40:51.856Z] 07:40:51     INFO -  PID 18915 |     #5 NS_NewNamedThread(nsTSubstring<char> const&, nsIThread**, already_AddRefed<nsIRunnable>, unsigned int) /builds/worker/checkouts/gecko/xpcom/threads/nsThreadUtils.cpp:157:57 (libxul.so+0xb085c8)
[task 2020-05-14T07:40:51.856Z] 07:40:51     INFO -  PID 18915 |     #6 NS_NewNamedThread<14> /builds/worker/workspace/obj-build/dist/include/nsThreadUtils.h:82:10 (libxul.so+0xc9f93a)
[task 2020-05-14T07:40:51.856Z] 07:40:51     INFO -  PID 18915 |     #7 mozilla::net::nsSocketTransportService::Init() /builds/worker/checkouts/gecko/netwerk/base/nsSocketTransportService2.cpp:729:7 (libxul.so+0xc9f93a)
[task 2020-05-14T07:40:51.856Z] 07:40:51     INFO -  PID 18915 |     #8 mozilla::xpcom::CreateInstanceImpl(mozilla::xpcom::ModuleID, nsISupports*, nsID const&, void**) /builds/worker/workspace/obj-build/xpcom/components/StaticComponents.cpp:8215:7 (libxul.so+0xac16bd)
[task 2020-05-14T07:40:51.857Z] 07:40:51     INFO -  PID 18915 |     #9 mozilla::xpcom::StaticModule::CreateInstance(nsISupports*, nsID const&, void**) const /builds/worker/workspace/obj-build/xpcom/components/StaticComponents.cpp:11432:10 (libxul.so+0xac0d10)
[task 2020-05-14T07:40:51.857Z] 07:40:51     INFO -  PID 18915 |     #10 CreateInstance /builds/worker/checkouts/gecko/xpcom/components/nsComponentManager.cpp:219:46 (libxul.so+0xad75a3)
[task 2020-05-14T07:40:51.857Z] 07:40:51     INFO -  PID 18915 |     #11 nsComponentManagerImpl::GetServiceLocked((anonymous namespace)::MutexLock&, (anonymous namespace)::EntryWrapper&, nsID const&, void**) /builds/worker/checkouts/gecko/xpcom/components/nsComponentManager.cpp:1372:17 (libxul.so+0xad75a3)
[task 2020-05-14T07:40:51.858Z] 07:40:51     INFO -  PID 18915 |     #12 nsComponentManagerImpl::GetServiceByContractID(char const*, nsID const&, void**) /builds/worker/checkouts/gecko/xpcom/components/nsComponentManager.cpp:1559:10 (libxul.so+0xad2623)
[task 2020-05-14T07:40:51.858Z] 07:40:51     INFO -  PID 18915 |     #13 CallGetService /builds/worker/checkouts/gecko/xpcom/components/nsComponentManagerUtils.cpp:61:43 (libxul.so+0xadaa6a)
[task 2020-05-14T07:40:51.858Z] 07:40:51     INFO -  PID 18915 |     #14 nsGetServiceByContractIDWithError::operator()(nsID const&, void**) const /builds/worker/checkouts/gecko/xpcom/components/nsComponentManagerUtils.cpp:253:21 (libxul.so+0xadaa6a)
[task 2020-05-14T07:40:51.858Z] 07:40:51     INFO -  PID 18915 |     #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+0xa22157)
[task 2020-05-14T07:40:51.859Z] 07:40:51     INFO -  PID 18915 |     #16 operator= /builds/worker/workspace/obj-build/dist/include/nsCOMPtr.h:762:5 (libxul.so+0xc46859)
[task 2020-05-14T07:40:51.859Z] 07:40:51     INFO -  PID 18915 |     #17 InitializeSocketTransportService /builds/worker/checkouts/gecko/netwerk/base/nsIOService.cpp:362:29 (libxul.so+0xc46859)
[task 2020-05-14T07:40:51.859Z] 07:40:51     INFO -  PID 18915 |     #18 mozilla::net::nsIOService::SetOffline(bool) /builds/worker/checkouts/gecko/netwerk/base/nsIOService.cpp:1248:7 (libxul.so+0xc46859)
[task 2020-05-14T07:40:51.860Z] 07:40:51     INFO -  PID 18915 |     #19 mozilla::net::nsIOService::Init() /builds/worker/checkouts/gecko/netwerk/base/nsIOService.cpp:303:3 (libxul.so+0xc45f50)
[task 2020-05-14T07:40:51.860Z] 07:40:51     INFO -  PID 18915 |     #20 mozilla::net::nsIOService::GetInstance() /builds/worker/checkouts/gecko/netwerk/base/nsIOService.cpp:418:9 (libxul.so+0xc474d1)
[task 2020-05-14T07:40:51.860Z] 07:40:51     INFO -  PID 18915 |     #21 mozilla::xpcom::CreateInstanceImpl(mozilla::xpcom::ModuleID, nsISupports*, nsID const&, void**) /builds/worker/workspace/obj-build/xpcom/components/StaticComponents.cpp:9870:48 (libxul.so+0xac33b7)
[task 2020-05-14T07:40:51.861Z] 07:40:51     INFO -  PID 18915 |     #22 mozilla::xpcom::StaticModule::CreateInstance(nsISupports*, nsID const&, void**) const /builds/worker/workspace/obj-build/xpcom/components/StaticComponents.cpp:11432:10 (libxul.so+0xac0d10)
[task 2020-05-14T07:40:51.861Z] 07:40:51     INFO -  PID 18915 |     #23 CreateInstance /builds/worker/checkouts/gecko/xpcom/components/nsComponentManager.cpp:219:46 (libxul.so+0xad75a3)
[task 2020-05-14T07:40:51.862Z] 07:40:51     INFO -  PID 18915 |     #24 nsComponentManagerImpl::GetServiceLocked((anonymous namespace)::MutexLock&, (anonymous namespace)::EntryWrapper&, nsID const&, void**) /builds/worker/checkouts/gecko/xpcom/components/nsComponentManager.cpp:1372:17 (libxul.so+0xad75a3)
[task 2020-05-14T07:40:51.862Z] 07:40:51     INFO -  PID 18915 |     #25 nsComponentManagerImpl::GetServiceByContractID(char const*, nsID const&, void**) /builds/worker/checkouts/gecko/xpcom/components/nsComponentManager.cpp:1559:10 (libxul.so+0xad2623)
[task 2020-05-14T07:40:51.863Z] 07:40:51     INFO -  PID 18915 |     #26 CallGetService(char const*, nsID const&, void**) /builds/worker/checkouts/gecko/xpcom/components/nsComponentManagerUtils.cpp:61:43 (libxul.so+0xada57d)
[task 2020-05-14T07:40:51.863Z] 07:40:51     INFO -  PID 18915 |     #27 CallGetService<nsIIOService> /builds/worker/workspace/obj-build/dist/include/nsServiceManagerUtils.h:72:10 (libxul.so+0x1c5c660)
[task 2020-05-14T07:40:51.864Z] 07:40:51     INFO -  PID 18915 |     #28 nsScriptSecurityManager::Init() /builds/worker/checkouts/gecko/caps/nsScriptSecurityManager.cpp:1368:17 (libxul.so+0x1c5c660)
[task 2020-05-14T07:40:51.864Z] 07:40:51     INFO -  PID 18915 |     #29 nsScriptSecurityManager::InitStatics() /builds/worker/checkouts/gecko/caps/nsScriptSecurityManager.cpp:1429:28 (libxul.so+0x1c5cf1e)
[task 2020-05-14T07:40:51.864Z] 07:40:51     INFO -  PID 18915 |     #30 nsXPConnect::InitStatics() /builds/worker/checkouts/gecko/js/xpconnect/src/nsXPConnect.cpp:153:3 (libxul.so+0x198c620)
[task 2020-05-14T07:40:51.865Z] 07:40:51     INFO -  PID 18915 |     #31 xpcModuleCtor() /builds/worker/checkouts/gecko/js/xpconnect/src/XPCModule.cpp:11:3 (libxul.so+0x19621ff)
[task 2020-05-14T07:40:51.865Z] 07:40:51     INFO -  PID 18915 |     #32 nsLayoutModuleInitialize() /builds/worker/checkouts/gecko/layout/build/nsLayoutModule.cpp:108:7 (libxul.so+0x4fcf0f7)
[task 2020-05-14T07:40:51.866Z] 07:40:51     INFO -  PID 18915 |     #33 nsComponentManagerImpl::Init() /builds/worker/checkouts/gecko/xpcom/components/nsComponentManager.cpp:482:5 (libxul.so+0xad3101)
[task 2020-05-14T07:40:51.866Z] 07:40:51     INFO -  PID 18915 |     #34 NS_InitXPCOM /builds/worker/checkouts/gecko/xpcom/build/XPCOMInit.cpp:445:51 (libxul.so+0xb2fdf6)
[task 2020-05-14T07:40:51.867Z] 07:40:51     INFO -  PID 18915 |     #35 XRE_XPCShellMain(int, char**, char**, XREShellData const*) /builds/worker/checkouts/gecko/js/xpconnect/src/XPCShellImpl.cpp:1204:10 (libxul.so+0x196fe5c)
[task 2020-05-14T07:40:51.867Z] 07:40:51     INFO -  PID 18915 |     #36 mozilla::BootstrapImpl::XRE_XPCShellMain(int, char**, char**, XREShellData const*) /builds/worker/checkouts/gecko/toolkit/xre/Bootstrap.cpp:54:12 (libxul.so+0x64582eb)
[task 2020-05-14T07:40:51.868Z] 07:40:51     INFO -  PID 18915 |     #37 main /builds/worker/checkouts/gecko/js/xpconnect/shell/xpcshell.cpp:66:27 (xpcshell+0xc8bd6)
[task 2020-05-14T07:40:51.868Z] 07:40:51     INFO -  PID 18915 | SUMMARY: ThreadSanitizer: lock-order-inversion (potential deadlock) /builds/worker/checkouts/gecko/mozglue/misc/Mutex_posix.cpp:118:3 in mutexLock
[task 2020-05-14T07:40:51.868Z] 07:40:51     INFO -  PID 18915 | ==================
[task 2020-05-14T07:40:51.869Z] 07:40:51     INFO -  <<<<<<<
Status: NEW → RESOLVED
Closed: 1 year ago
Resolution: --- → INCOMPLETE
Blocks: tsan
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---

Oops! This is Bug 1608462.

I accidentally reverted the wrong thing in https://hg.mozilla.org/mozilla-central/rev/6e297cea9592ca843887c294fec3bed8327e8b87

(two similar entries, one lock, one race, got them mixed up)

I think some wires got crossed, the last intermittent report is races that should be associated with Bug 1626534.

The issue tracked by this bug was properly fixed in Bug 1608462.

Status: REOPENED → RESOLVED
Closed: 1 year ago5 months ago
Resolution: --- → DUPLICATE
Duplicate of bug: 1608462
You need to log in before you can comment on or make changes to this bug.