1829445 - Permanent SUMMARY: ThreadSanitizer: lock-order-inversion (potential deadlock) /builds/worker/checkouts/gecko/xpcom/threads/RecursiveMutex.cpp:71:3 in mozilla::RecursiveMutex::LockInternal() in TestHttpResponseHead.Bug1636930

Status: RESOLVED FIXED

(Core :: Networking: HTTP, defect, P2)

Description

[Treeherder Bug Filer]

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

---

Found while attempting to enable TSAN for GTests. Hits consistently during TestHttpResponseHead.Bug1636930.

Comment 1

[Intermittent Failures Robot]

20 failures in 158 pushes (0.127 failures/push) were associated with this bug yesterday.

Repository breakdown:

• try: 20

Platform and build breakdown:

• linux1804-64-tsan-qr: 20
  • opt: 20

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1829445&startday=2023-04-22&endday=2023-04-22&tree=all

Comment 2

[Intermittent Failures Robot]

20 failures in 4004 pushes (0.005 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• try: 20

Platform and build breakdown:

• linux1804-64-tsan-qr: 20
  • opt: 20

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1829445&startday=2023-04-17&endday=2023-04-23&tree=all

Comment 3

[Randell Jesup [:jesup] (needinfo me)]

May only happen in the test code

Comment 4

[Intermittent Failures Robot]

1 failures in 3411 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 1

Platform and build breakdown:

• linux1804-64-tsan-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1829445&startday=2023-05-01&endday=2023-05-07&tree=all

Comment 5

[Ryan VanderMeulen [:RyanVM]]

FWIW, this may be test-only but ultimately is blocking our ability to enable gtests in TSAN mode in CI.

Comment 6

[Valentin Gosu [:valentin]]

Let's either skip the test (return 0 #if MOZ_TSAN) or actually fix it if straightforward.

Comment 7

[Intermittent Failures Robot]

1 failures in 3471 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• try: 1

Platform and build breakdown:

• linux1804-64-tsan-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1829445&startday=2023-05-29&endday=2023-06-04&tree=all

Comment 8

[Sunil Mayya]

Pasting the logs here for reference

[task 2023-05-30T14:32:20.480Z] 14:32:20     INFO -  WARNING: ThreadSanitizer: lock-order-inversion (potential deadlock) (pid=1541)
[task 2023-05-30T14:32:20.481Z] 14:32:20     INFO -    Cycle in lock order graph: M0 (0x7ffc2b53f168) => M1 (0x7ffc2b53f080) => M0
[task 2023-05-30T14:32:20.481Z] 14:32:20     INFO -    Mutex M1 acquired here while holding mutex M0 in main thread:
[task 2023-05-30T14:32:20.482Z] 14:32:20     INFO -      #0 pthread_mutex_lock /builds/worker/fetches/llvm-project/compiler-rt/lib/tsan/rtl/tsan_interceptors_posix.cpp:1367:3 (firefox-bin+0xad8db) (BuildId: d4a204e962bc4f853ce6a1d9c308d74672f27299)
[task 2023-05-30T14:32:20.482Z] 14:32:20     INFO -      #1 mozilla::RecursiveMutex::LockInternal() /builds/worker/checkouts/gecko/xpcom/threads/RecursiveMutex.cpp:71:3 (libxul.so+0x68636d5) (BuildId: d70bada884f43cfcc1b77bb88645797de8a08e6a)
[task 2023-05-30T14:32:20.483Z] 14:32:20     INFO -      #2 Lock /builds/worker/workspace/obj-build/dist/include/mozilla/RecursiveMutex.h:31:42 (libxul.so+0x71e5882) (BuildId: d70bada884f43cfcc1b77bb88645797de8a08e6a)
[task 2023-05-30T14:32:20.483Z] 14:32:20     INFO -      #3 RecursiveMutexAutoLock /builds/worker/workspace/obj-build/dist/include/mozilla/RecursiveMutex.h:80:22 (libxul.so+0x71e5882)
[task 2023-05-30T14:32:20.494Z] 14:32:20     INFO -      #4 mozilla::net::nsHttpResponseHead::operator=(mozilla::net::nsHttpResponseHead const&) /builds/worker/checkouts/gecko/netwerk/protocol/http/nsHttpResponseHead.cpp:58:26 (libxul.so+0x71e5882)
[task 2023-05-30T14:32:20.494Z] 14:32:20     INFO -      #5 mozilla::net::AssertRoundTrips(mozilla::net::nsHttpResponseHead const&) /builds/worker/checkouts/gecko/netwerk/test/gtest/TestHttpResponseHead.cpp:35:12 (libxul.so+0x4c8b388) (BuildId: d70bada884f43cfcc1b77bb88645797de8a08e6a)
[task 2023-05-30T14:32:20.494Z] 14:32:20     INFO -      #6 mozilla::net::TestHttpResponseHead_Bug1636930_Test::TestBody() /builds/worker/checkouts/gecko/netwerk/test/gtest/TestHttpResponseHead.cpp:54:3 (libxul.so+0x4c8c2bf) (BuildId: d70bada884f43cfcc1b77bb88645797de8a08e6a)
[task 2023-05-30T14:32:20.494Z] 14:32:20     INFO -      #7 void testing::internal::HandleExceptionsInMethodIfSupported<testing::Test, void>(testing::Test*, void (testing::Test::*)(), char const*) /builds/worker/checkouts/gecko/third_party/googletest/googletest/src/gtest.cc (libxul.so+0x522096d) (BuildId: d70bada884f43cfcc1b77bb88645797de8a08e6a)
[task 2023-05-30T14:32:20.495Z] 14:32:20     INFO -      #8 testing::Test::Run() /builds/worker/checkouts/gecko/third_party/googletest/googletest/src/gtest.cc:2674:5 (libxul.so+0x52207d9) (BuildId: d70bada884f43cfcc1b77bb88645797de8a08e6a)
[task 2023-05-30T14:32:20.495Z] 14:32:20     INFO -      #9 testing::TestInfo::Run() /builds/worker/checkouts/gecko/third_party/googletest/googletest/src/gtest.cc:2853:11 (libxul.so+0x52221d8) (BuildId: d70bada884f43cfcc1b77bb88645797de8a08e6a)
[task 2023-05-30T14:32:20.495Z] 14:32:20     INFO -      #10 testing::TestSuite::Run() /builds/worker/checkouts/gecko/third_party/googletest/googletest/src/gtest.cc:3012:30 (libxul.so+0x52237f4) (BuildId: d70bada884f43cfcc1b77bb88645797de8a08e6a)
[task 2023-05-30T14:32:20.495Z] 14:32:20     INFO -      #11 testing::internal::UnitTestImpl::RunAllTests() /builds/worker/checkouts/gecko/third_party/googletest/googletest/src/gtest.cc:5870:44 (libxul.so+0x5243059) (BuildId: d70bada884f43cfcc1b77bb88645797de8a08e6a)
[task 2023-05-30T14:32:20.495Z] 14:32:20     INFO -      #12 bool testing::internal::HandleExceptionsInMethodIfSupported<testing::internal::UnitTestImpl, bool>(testing::internal::UnitTestImpl*, bool (testing::internal::UnitTestImpl::*)(), char const*) /builds/worker/checkouts/gecko/third_party/googletest/googletest/src/gtest.cc (libxul.so+0x52427fd) (BuildId: d70bada884f43cfcc1b77bb88645797de8a08e6a)
[task 2023-05-30T14:32:20.496Z] 14:32:20     INFO -      #13 testing::UnitTest::Run() /builds/worker/checkouts/gecko/third_party/googletest/googletest/src/gtest.cc:5444:10 (libxul.so+0x52425a0) (BuildId: d70bada884f43cfcc1b77bb88645797de8a08e6a)
[task 2023-05-30T14:32:20.496Z] 14:32:20     INFO -      #14 RUN_ALL_TESTS /builds/worker/workspace/obj-build/dist/include/gtest/gtest.h:2295:73 (libxul.so+0x51e39dd) (BuildId: d70bada884f43cfcc1b77bb88645797de8a08e6a)
[task 2023-05-30T14:32:20.496Z] 14:32:20     INFO -      #15 mozilla::RunGTestFunc(int*, char**) /builds/worker/checkouts/gecko/testing/gtest/mozilla/GTestRunner.cpp:167:10 (libxul.so+0x51e39dd)
[task 2023-05-30T14:32:20.496Z] 14:32:20     INFO -      #16 XREMain::XRE_mainStartup(bool*) /builds/worker/checkouts/gecko/toolkit/xre/nsAppRunner.cpp:4671:16 (libxul.so+0xe361798) (BuildId: d70bada884f43cfcc1b77bb88645797de8a08e6a)
[task 2023-05-30T14:32:20.497Z] 14:32:20     INFO -      #17 XREMain::XRE_main(int, char**, mozilla::BootstrapConfig const&) /builds/worker/checkouts/gecko/toolkit/xre/nsAppRunner.cpp:5847:12 (libxul.so+0xe3696ca) (BuildId: d70bada884f43cfcc1b77bb88645797de8a08e6a)
[task 2023-05-30T14:32:20.497Z] 14:32:20     INFO -      #18 XRE_main(int, char**, mozilla::BootstrapConfig const&) /builds/worker/checkouts/gecko/toolkit/xre/nsAppRunner.cpp:5915:21 (libxul.so+0xe369e61) (BuildId: d70bada884f43cfcc1b77bb88645797de8a08e6a)
[task 2023-05-30T14:32:20.497Z] 14:32:20     INFO -      #19 mozilla::BootstrapImpl::XRE_main(int, char**, mozilla::BootstrapConfig const&) /builds/worker/checkouts/gecko/toolkit/xre/Bootstrap.cpp:45:12 (libxul.so+0xe379532) (BuildId: d70bada884f43cfcc1b77bb88645797de8a08e6a)
[task 2023-05-30T14:32:20.497Z] 14:32:20     INFO -      #20 do_main /builds/worker/checkouts/gecko/browser/app/nsBrowserApp.cpp:227:22 (firefox-bin+0x13478e) (BuildId: d4a204e962bc4f853ce6a1d9c308d74672f27299)
[task 2023-05-30T14:32:20.497Z] 14:32:20     INFO -      #21 main /builds/worker/checkouts/gecko/browser/app/nsBrowserApp.cpp:445:16 (firefox-bin+0x13478e)
[task 2023-05-30T14:32:20.497Z] 14:32:20     INFO -      Hint: use TSAN_OPTIONS=second_deadlock_stack=1 to get more informative warning message
[task 2023-05-30T14:32:20.497Z] 14:32:20     INFO -    Mutex M0 acquired here while holding mutex M1 in main thread:
[task 2023-05-30T14:32:20.497Z] 14:32:20     INFO -      #0 pthread_mutex_lock /builds/worker/fetches/llvm-project/compiler-rt/lib/tsan/rtl/tsan_interceptors_posix.cpp:1367:3 (firefox-bin+0xad8db) (BuildId: d4a204e962bc4f853ce6a1d9c308d74672f27299)
[task 2023-05-30T14:32:20.497Z] 14:32:20     INFO -      #1 mozilla::RecursiveMutex::LockInternal() /builds/worker/checkouts/gecko/xpcom/threads/RecursiveMutex.cpp:71:3 (libxul.so+0x68636d5) (BuildId: d70bada884f43cfcc1b77bb88645797de8a08e6a)
[task 2023-05-30T14:32:20.497Z] 14:32:20     INFO -      #2 Lock /builds/worker/workspace/obj-build/dist/include/mozilla/RecursiveMutex.h:31:42 (libxul.so+0x71e88c3) (BuildId: d70bada884f43cfcc1b77bb88645797de8a08e6a)
[task 2023-05-30T14:32:20.497Z] 14:32:20     INFO -      #3 RecursiveMutexAutoLock /builds/worker/workspace/obj-build/dist/include/mozilla/RecursiveMutex.h:80:22 (libxul.so+0x71e88c3)
[task 2023-05-30T14:32:20.497Z] 14:32:20     INFO -      #4 mozilla::net::nsHttpResponseHead::operator==(mozilla::net::nsHttpResponseHead const&) const /builds/worker/checkouts/gecko/netwerk/protocol/http/nsHttpResponseHead.cpp:1054:26 (libxul.so+0x71e88c3)
[task 2023-05-30T14:32:20.497Z] 14:32:20     INFO -      #5 CmpHelperEQ<mozilla::net::nsHttpResponseHead, mozilla::net::nsHttpResponseHead> /builds/worker/workspace/obj-build/dist/include/gtest/gtest.h:1360:11 (libxul.so+0x4c8b393) (BuildId: d70bada884f43cfcc1b77bb88645797de8a08e6a)
[task 2023-05-30T14:32:20.497Z] 14:32:20     INFO -      #6 Compare<mozilla::net::nsHttpResponseHead, mozilla::net::nsHttpResponseHead, nullptr> /builds/worker/workspace/obj-build/dist/include/gtest/gtest.h:1379:12 (libxul.so+0x4c8b393)
[task 2023-05-30T14:32:20.497Z] 14:32:20     INFO -      #7 mozilla::net::AssertRoundTrips(mozilla::net::nsHttpResponseHead const&) /builds/worker/checkouts/gecko/netwerk/test/gtest/TestHttpResponseHead.cpp:36:5 (libxul.so+0x4c8b393)
[task 2023-05-30T14:32:20.497Z] 14:32:20     INFO -      #8 mozilla::net::TestHttpResponseHead_Bug1636930_Test::TestBody() /builds/worker/checkouts/gecko/netwerk/test/gtest/TestHttpResponseHead.cpp:54:3 (libxul.so+0x4c8c2bf) (BuildId: d70bada884f43cfcc1b77bb88645797de8a08e6a)
[task 2023-05-30T14:32:20.497Z] 14:32:20     INFO -      #9 void testing::internal::HandleExceptionsInMethodIfSupported<testing::Test, void>(testing::Test*, void (testing::Test::*)(), char const*) /builds/worker/checkouts/gecko/third_party/googletest/googletest/src/gtest.cc (libxul.so+0x522096d) (BuildId: d70bada884f43cfcc1b77bb88645797de8a08e6a)
[task 2023-05-30T14:32:20.497Z] 14:32:20     INFO -      #10 testing::Test::Run() /builds/worker/checkouts/gecko/third_party/googletest/googletest/src/gtest.cc:2674:5 (libxul.so+0x52207d9) (BuildId: d70bada884f43cfcc1b77bb88645797de8a08e6a)
[task 2023-05-30T14:32:20.497Z] 14:32:20     INFO -      #11 testing::TestInfo::Run() /builds/worker/checkouts/gecko/third_party/googletest/googletest/src/gtest.cc:2853:11 (libxul.so+0x52221d8) (BuildId: d70bada884f43cfcc1b77bb88645797de8a08e6a)
[task 2023-05-30T14:32:20.497Z] 14:32:20     INFO -      #12 testing::TestSuite::Run() /builds/worker/checkouts/gecko/third_party/googletest/googletest/src/gtest.cc:3012:30 (libxul.so+0x52237f4) (BuildId: d70bada884f43cfcc1b77bb88645797de8a08e6a)
[task 2023-05-30T14:32:20.497Z] 14:32:20     INFO -      #13 testing::internal::UnitTestImpl::RunAllTests() /builds/worker/checkouts/gecko/third_party/googletest/googletest/src/gtest.cc:5870:44 (libxul.so+0x5243059) (BuildId: d70bada884f43cfcc1b77bb88645797de8a08e6a)
[task 2023-05-30T14:32:20.497Z] 14:32:20     INFO -      #14 bool testing::internal::HandleExceptionsInMethodIfSupported<testing::internal::UnitTestImpl, bool>(testing::internal::UnitTestImpl*, bool (testing::internal::UnitTestImpl::*)(), char const*) /builds/worker/checkouts/gecko/third_party/googletest/googletest/src/gtest.cc (libxul.so+0x52427fd) (BuildId: d70bada884f43cfcc1b77bb88645797de8a08e6a)
[task 2023-05-30T14:32:20.497Z] 14:32:20     INFO -      #15 testing::UnitTest::Run() /builds/worker/checkouts/gecko/third_party/googletest/googletest/src/gtest.cc:5444:10 (libxul.so+0x52425a0) (BuildId: d70bada884f43cfcc1b77bb88645797de8a08e6a)
[task 2023-05-30T14:32:20.498Z] 14:32:20     INFO -      #16 RUN_ALL_TESTS /builds/worker/workspace/obj-build/dist/include/gtest/gtest.h:2295:73 (libxul.so+0x51e39dd) (BuildId: d70bada884f43cfcc1b77bb88645797de8a08e6a)
[task 2023-05-30T14:32:20.499Z] 14:32:20     INFO -      #17 mozilla::RunGTestFunc(int*, char**) /builds/worker/checkouts/gecko/testing/gtest/mozilla/GTestRunner.cpp:167:10 (libxul.so+0x51e39dd)
[task 2023-05-30T14:32:20.499Z] 14:32:20     INFO -      #18 XREMain::XRE_mainStartup(bool*) /builds/worker/checkouts/gecko/toolkit/xre/nsAppRunner.cpp:4671:16 (libxul.so+0xe361798) (BuildId: d70bada884f43cfcc1b77bb88645797de8a08e6a)
[task 2023-05-30T14:32:20.499Z] 14:32:20     INFO -      #19 XREMain::XRE_main(int, char**, mozilla::BootstrapConfig const&) /builds/worker/checkouts/gecko/toolkit/xre/nsAppRunner.cpp:5847:12 (libxul.so+0xe3696ca) (BuildId: d70bada884f43cfcc1b77bb88645797de8a08e6a)
[task 2023-05-30T14:32:20.500Z] 14:32:20     INFO -      #20 XRE_main(int, char**, mozilla::BootstrapConfig const&) /builds/worker/checkouts/gecko/toolkit/xre/nsAppRunner.cpp:5915:21 (libxul.so+0xe369e61) (BuildId: d70bada884f43cfcc1b77bb88645797de8a08e6a)
[task 2023-05-30T14:32:20.500Z] 14:32:20     INFO -      #21 mozilla::BootstrapImpl::XRE_main(int, char**, mozilla::BootstrapConfig const&) /builds/worker/checkouts/gecko/toolkit/xre/Bootstrap.cpp:45:12 (libxul.so+0xe379532) (BuildId: d70bada884f43cfcc1b77bb88645797de8a08e6a)
[task 2023-05-30T14:32:20.501Z] 14:32:20     INFO -      #22 do_main /builds/worker/checkouts/gecko/browser/app/nsBrowserApp.cpp:227:22 (firefox-bin+0x13478e) (BuildId: d4a204e962bc4f853ce6a1d9c308d74672f27299)

Comment 9

[Sunil Mayya]

Attachment: Bug 1829445 - fix lock-order-inversion problem in TestHttpResponseHead::AssertRoundTrips(). r=#necko,jesup

The operators = and == in nsHttpResponseHead acquires mutexes in a particular order.
The mutex of the argument for the =/== is acquired first followed by the object's own mutex.
The code in TestHttpResponseHead::AssertRoundTrips() uses both the operators and the order of arguments passed to the == can present a possible dead-lock problem as reported by the TSAN.

Comment 10

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/a8629685bd4f
fix lock-order-inversion problem in TestHttpResponseHead::AssertRoundTrips(). r=jesup,necko-reviewers

Comment 11

[Sandor Molnar[:smolnar]]

https://hg.mozilla.org/mozilla-central/rev/a8629685bd4f