1657174 - Crash in [@ profiler_unregister_thread]

Status: RESOLVED FIXED

(Core :: Gecko Profiler, defect, P1)

Description

[Kevin Brosnan [Ex-Mozilla]]

This bug is for crash report bp-7077bc88-239c-4c11-9a3a-470e50200804.

Top 8 frames of crashing thread:

0 libxul.so profiler_unregister_thread tools/profiler/core/platform.cpp:5005
1 libxul.so nsThread::ThreadFunc xpcom/threads/nsThread.cpp:476
2 libnss3.so _pt_root nsprpub/pr/src/pthreads/ptthread.c:201
3 libc.so libc.so@0x48811 
4 libc.so libc.so@0x487f7 
5 libc.so libc.so@0x1b369 
6 libc.so libc.so@0x487f7 
7 libnss3.so pt_recvfrom_cont nsprpub/pr/src/pthreads/ptio.c:987

Comment 1

[Kevin Brosnan [Ex-Mozilla]]

This is the top crash for Fenix nightly. Looks like it was introduced on July 17.

Comment 2

[Gerald Squelart (he/him) (not at Mozilla since 2022-09-15)]

So this is most probably the follow-up to bug 1651086, where we fixed crashes from multiple locked_register_thread() by allowing these multiple registrations. Now we're seeing the complementary multiple profiler_unregister_thread() calls.
The root cause (aka "regressed by" bug) is still unknown.

This can happen even for people not using the profiler -> P1 S2.

Like bug 1651086, I'll make a quick fix to allow these multiple de-registrations. But it would be good to investigate the real issue, I'll open a follow-up bug for that...

Comment 3

[Gerald Squelart (he/him) (not at Mozilla since 2022-09-15)]

Actually, looking at the code, this is a regression by bug 1651086, which handled multiple de-registrations, but left an assertion at the wrong place! 😅

Comment 4

[Gerald Squelart (he/him) (not at Mozilla since 2022-09-15)]

Attachment: Bug 1657174 - Added more targeted assertions around multiple thread de-registrations - r?mstange

MOZ_RELEASE_ASSERT(registeredThread == TLSRegisteredThread::RegisteredThread(lock)); is failing on Android, probably as a follow-up to bug 1651086, which allowed multiple registrations (to fix a problem with yet-unknown root cause).
This assertion is too broad to help find the issue because at this point:

• If FindCurrentThreadRegisteredThread() is not null, TLSRegisteredThread::RegisteredThread() should also not be null, and it should equal FindCurrentThreadRegisteredThread(), from the first succesful profiler_register_thread().
• If FindCurrentThreadRegisteredThread() is null, TLSRegisteredThread::RegisteredThread() should be null as well, from the first profiler_unregister_thread().

So this patch splits this assertion into multiple more targeted ones to check the above, and also some extra assertions after de-registration, to ensure that both FindCurrentThreadRegisteredThread() and TLSRegisteredThread::RegisteredThread() are null.

Comment 5

[Gerald Squelart (he/him) (not at Mozilla since 2022-09-15)]

After discussing this with :mstange, he suggested we split the failing assertion to have a better idea of what's happening.

This is only an exploratory patch, it will not fix the problem. So this bug should be kept open, and I'll monitor crashes over the next few days...

Comment 6

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/63866b83d444
Added more targeted assertions around multiple thread de-registrations - r=mstange

Comment 7

[BugBot [:suhaib / :marco/ :calixte]]

Set release status flags based on info from the regressing bug 1651086

Comment 8

[Natalia Csoregi [:nataliaCs]]

https://hg.mozilla.org/mozilla-central/rev/63866b83d444

Comment 9

[Gerald Squelart (he/him) (not at Mozilla since 2022-09-15)]

I'm confused: There are now 85 reports with the buildid (20200806033456) on which the exploratory patch landed, however when looking at these reports, they all link to a source without that patch. 🤔

I will keep monitoring, hopefully the next released version will have our patch...

Comment 10

[Markus Stange [:mstange]]

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

I'm confused: There are now 85 reports with the buildid (20200806033456) on which the exploratory patch landed

No, that build was built from https://hg.mozilla.org/mozilla-central/rev/6e35e01646d7c465893a172a0b4fb116c2293d2a, which is from m-c push 37674, and your patch landed in push 37675.

Comment 11

[Gerald Squelart (he/him) (not at Mozilla since 2022-09-15)]

(In reply to Markus Stange [:mstange] from comment #10)

No, that build was built from [...] m-c push 37674, and your patch landed in push 37675.

Oooh, so close! Next one, then... 😅

Comment 12

[Julien Cristau [:jcristau]]

Looks like we're still seeing this signature on Fenix with GV buildid 20200808213325.
Crash reason is MOZ_RELEASE_ASSERT(TLSRegisteredThread::RegisteredThread(lock))

Comment 13

[Gerald Squelart (he/him) (not at Mozilla since 2022-09-15)]

Thank you Julien.
Yes, we finally have reports with the exploratory patch. So we have a bit more information about what went wrong:

I can see almost all reports (e.g., this one) happen at MOZ_RELEASE_ASSERT(!TLSRegisteredThread::RegisteredThread(lock)); in the already-unregistered branch.
I'm guessing either:

• This is the 2nd profiler_unregister_thread() on a thread, and somehow the TLS was not cleared; but it should have been reset in the previous call at line 5117.
• This is a spurious profiler_unregister_thread() on a never-registered thread, in which case the TLS should be null anyway.

There was also a single report out of the ~50 I looked at, which failed at MOZ_RELEASE_ASSERT(TLSRegisteredThread::RegisteredThread(lock)); in the still-registered-as-expected branch. So we have a registered thread without a TLS, which is strange since we set the TLS before adding the thread to the register.

I will try to trace all paths through profiler_register_thread() and profiler_unregister_thread(), to see how this situation could happen.

It's also interesting that this almost only happens on Android, what could be so different from other platforms?

Comment 14

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

I'd strongly expect it's some type of race; threading and scheduler models are quite different (and likely so even between linux desktop and android), so that's not that surprising that one platform is far more affected. There are ~100 windows assertions in crash-stats, though, so I think there's a fundamental assumption here that's wrong.

Comment 15

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

-> All since it asserts on windows too

Comment 16

[Gerald Squelart (he/him) (not at Mozilla since 2022-09-15)]

And there are a few on Mac as well.

My first attempt at tracing register+unregister on paper didn't help, I'll continue investigating... Fresh eyes welcome!

Comment 17

[Gerald Squelart (he/him) (not at Mozilla since 2022-09-15)]

Oh dear: I've just noticed that even though almost all reports point at line 5148 which does MOZ_RELEASE_ASSERT(!TLSRegisteredThread::RegisteredThread(lock)), the "MOZ_CRASH Reason" is actually MOZ_RELEASE_ASSERT(TLSRegisteredThread::RegisteredThread(lock)) (without '!') which is at line 5103! 🤦‍♂️
The 2nd unregistration problem was a red herring.

The real issue is that we have a still-registered thread, but the TLS is unexpectedly null.
Restarting my investigation...

Comment 18

[Gerald Squelart (he/him) (not at Mozilla since 2022-09-15)]

Attachment: Bug 1657174 - Added more (un)registration TLS assertions - r?mstange

Assertions are also clarified with messages, to better distinguish the same tests in different locations.

Assertions should now cover all cases:

• NEW: After registering a thread in the profiler with CorePS::AppendRegisteredThread, the TLS should be set to that thread.
• NEW: If profiler_register_thread is called again, the TLS should still be set to that thread.
• When profiler_unregister_thread is first called, the TLS should still be set to that thread (that's the assertion currently trigering this bug 1657174),
• NEW: When profiler_unregister_thread is first called and after we remove the thread with CorePS::RemoveRegisteredThread, the TLS should now be null.
• If profiler_unregister_thread is called again (or with a never-registered thread), the TLS should be null.

This is a further exploratory patch for bug 1657174, this will not prevent crashes, but hopefully it should give a bit more information, at least a smaller range in which the possible presumed registration/TLS race happens.

Comment 19

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/73ad83f70029
Added more (un)registration TLS assertions - r=mstange

Comment 20

[Atila Butkovits]

https://hg.mozilla.org/mozilla-central/rev/73ad83f70029

Comment 21

[Gerald Squelart (he/him) (not at Mozilla since 2022-09-15)]

I'm not seeing crash reports past 20200818092452, so I'm cautiously optimistic (and pleasantly surprised) that bug 1659901 may have in fact solved this bug! If that's correct, it means we had some misuses around TLS objects.

I will keep monitoring crash reports a while longer before declaring victory...

Comment 22

[Gerald Squelart (he/him) (not at Mozilla since 2022-09-15)]

Still no new reports after Fenix 0.0a1 20200818092452. I'm declaring this bug fixed.

Comment 23

[Gerald Squelart (he/him) (not at Mozilla since 2022-09-15)]

Comment on attachment 9168335 [details]
Bug 1657174 - Added more targeted assertions around multiple thread de-registrations - r?mstange

Beta/Release Uplift Approval Request

• User impact if declined: Crashes
• Is this code covered by automated tests?: Yes
• Has the fix been verified in Nightly?: Yes
• Needs manual test from QE?: No
• If yes, steps to reproduce:
• List of other uplifts needed: None
• Risk to taking this patch: Low
• Why is the change risky/not risky? (and alternatives if risky): Only assertions, needed to uplift bug 1659901

Note: There is another patch in thus bug, see attachment 9170931 [details].

• String changes made/needed: None

Comment 24

[Ryan VanderMeulen [:RyanVM]]

Comment on attachment 9168335 [details]
Bug 1657174 - Added more targeted assertions around multiple thread de-registrations - r?mstange

Approved for GV80 for Fenix 80.1.3.

Comment 25

[Ryan VanderMeulen [:RyanVM]]

https://hg.mozilla.org/releases/mozilla-release/rev/081b2f90cc97
https://hg.mozilla.org/releases/mozilla-release/rev/cfa7e7bbe516

Comment 26

[Markus Stange [:mstange]]

The crashes are not gone, they just moved from profiler_unregister_thread to profiler_register_thread. Analysis continues in bug 1666246.