1403968 - Perf Profiling slack with debugger causes crash

Status: RESOLVED WORKSFORME

(Core :: Gecko Profiler, defect, P1)

Description

[Yulia Startsev [:yulia] OOO until July 2026]

Attachment: perf-html crash

steps to reproduce:

1) Open slack.com and join a channel, and start the perf-html addon
2) open the debugger panel
3) select a file from the debugger panel
4) reload slack using cmd-r (this will take some time)
5) once slack has reloaded, try to open the profiler using ctrl-shift-2

sometimes it will crash. not always. crash looked like the attachment

Comment 1

[Markus Stange [:mstange]]

https://crash-stats.mozilla.com/report/index/be53341b-5ca2-44fb-a492-bcc870170928#tab-details

We're crashing at this assert:

>       } else if (e.Get().IsJitReturnAddr()) {
>         numFrames++;
> 
>         // A JIT frame may expand to multiple frames due to inlining.
>         void* pc = e.Get().u.mPtr;
>         unsigned depth = aUniqueStacks.LookupJITFrameDepth(pc);
>         if (depth == 0) {
>           StreamJSFramesOp framesOp(pc, stack);
> -->       MOZ_RELEASE_ASSERT(aContext);
>           JS::ForEachProfiledFrame(aContext, pc, framesOp);
>           aUniqueStacks.AddJITFrameDepth(pc, framesOp.depth());

Comment 2

[Kannan Vijayan [:djvj]]

Well, it looks from this that the assert is just wrong.  The |aContext| here is passed in directly from the thread's |mContext| higher up in the call stack.  There are no mutations done, so if |aContext| is null, it's because the thread's |mContext| field was null from the start.

What thread is this happening on?

Comment 3

[Nicholas Nethercote [inactive]]

I added this assertion a while back. There are two ways to call StreamSamplesToJSON().

(1) The one from ProfilerBacktrace::StreamJSON() (which goes via StreamSamplesAndMarkers()) explicitly passes in a null aContext. This is ok because that's a "synchronous" sample obtained with profiler_get_backtrace(), which never contains JitReturnAddr entries.

(2) The other ones (ThreadInfo::StreamJSON() via StreamSamplesAndMarkers(), and ThreadInfo::FlushSamplesAndMarkers()) pass in an mContext from a ThreadInfo. The latter of these two asserts that mContext is non-null, but it's just a vanilla assert, not a release-assert.

So, the failing assertion was meant to capture the distinction between (1) and (2). It's non-obvious because I never managed to restructure this part of the code to capture the distinction more nicely. My assumption here was that the mContext from the ThreadInfo is never null, but it sounds like that's just wrong? How can a ThreadInfo (a) have a null mContext, and (b) also have JIT return addresses in its profile?

Comment 4

[Nicholas Nethercote [inactive]]

Attachment: Wrap ProfileBuffer::StreamSamplesToJSON()'s aContext argument in a Maybe<>

I wasn't able to reproduce the crash, but if I've understood it correctly this
should fix the problem.

Comment 5

[Nicholas Nethercote [inactive]]

> I wasn't able to reproduce the crash, but if I've understood it correctly
> this should fix the problem.

Wait, no, it won't. The Maybe<> makes things slightly clearer, but won't fix the crash, because the MOZ_RELEASE_ASSERT is immediately followed by a call to JS::ForEachProfiledFrame(), which repeatedly derefs `aContext`. So the assertion is not incorrect, and if it wasn't there we would have crashed immediately afterwards in JS::ForEachProfiledFrame().

So the question is: how do we end up with a thread that has JIT return addresses in its samples, but has a null mContext? And is that a legitimate case or not?

Comment 6

[Kannan Vijayan [:djvj]]

Comment on attachment 8914149 [details] [diff] [review]
Wrap ProfileBuffer::StreamSamplesToJSON()'s aContext argument in a Maybe<>

Review of attachment 8914149 [details] [diff] [review]:
-----------------------------------------------------------------

::: tools/profiler/core/ProfileBufferEntry.cpp
@@ +855,5 @@
>          unsigned depth = aUniqueStacks.LookupJITFrameDepth(pc);
>          if (depth == 0) {
>            StreamJSFramesOp framesOp(pc, stack);
> +          MOZ_RELEASE_ASSERT(aContext.isSome());
> +          JS::ForEachProfiledFrame(*aContext, pc, framesOp);

You probably want to check for |if (aContext)| around this.

Comment 7

[Kannan Vijayan [:djvj]]

(In reply to Nicholas Nethercote [:njn] from comment #5)
> So the question is: how do we end up with a thread that has JIT return
> addresses in its samples, but has a null mContext? And is that a legitimate
> case or not?

This is the question I had as well.  Is this potentially happening after the thread has been de-initialized and the mContext cleared?

The STR includes a reload before profiling, so it's a slight hint in that direction.

Comment 8

[Kannan Vijayan [:djvj]]

Check this out:

http://searchfox.org/mozilla-central/source/tools/profiler/core/platform.cpp#1652

This is where the call to StreamJSON is happening in the call stack.  It's in a loop where we iterate over dead threads and stream their samples.  So this is definitely a "dead" thread and somewhere something is cleaning up the mContext when it shouldn't be, or we're assuming an mContext when we shouldn't be (dead threads might be specified to have empty mContexts).

A simple immediate patch for this would be to simply skip streaming for dead threads.  However, this might mean that you lose profiling information that you captured before a reload.  Is that something people care about?

Comment 9

[Markus Stange [:mstange]]

ThreadInfo::FlushSamplesAndMarkers is supposed to take care of this problem: It causes us to serialize the profile of a thread to JSON when the thread loses its JSContext. We then hold on to that JSON and insert it into the complete profile the next time a profile is requested.

Comment 10

[Kannan Vijayan [:djvj]]

Thanks for that, Markus.  You're exactly right, FlushSamplesAndMarkers _does_ serialize the info before mContext is destroyed, and the serialized info is used here:

http://searchfox.org/mozilla-central/source/tools/profiler/core/ThreadInfo.cpp#198

Not coincidentally, the call to |streamSamplesToJSON| in our call stack is the one that occurs exactly AFTER the usage of |aSavedStreamSamples| in the caller |StreamSamplesAndMarkers|.

So a NULL check around aContext here:

http://searchfox.org/mozilla-central/source/tools/profiler/core/ThreadInfo.cpp#205

Should do the trick...?

Comment 11

[Kannan Vijayan [:djvj]]

Attachment: fix-bug-1403968.patch

Comment 12

[Markus Stange [:mstange]]

Hmm, no, I don't think this is right.
Let's say we have a large enough buffer. We start the profiler at time A, clear the JSContext at time B, and capture the profile at time C. Your patch would mean that the resulting profile has no samples for the time between B and C.

The way this is supposed to work is: At B, we stream the samples from between A and B to mSavedStreamedSamples, and reset the buffer [1]. At C, we first insert mSavedStreamedSamples, and then add the stream out the samples that are in the buffer now, which will only be samples that have been captured between B and C.

So I think what we need to find out is why the streaming operation at C finds samples in the buffer that need the JS context, even though the buffer is only supposed to contain samples that have been captured after B.

[1] http://searchfox.org/mozilla-central/source/tools/profiler/core/ThreadInfo.cpp#279-281 :

>  // Reset the buffer. Attempting to symbolicate JS samples after mContext has
>  // gone away will crash.
>  aBuffer.Reset();

Comment 13

[Nicholas Nethercote [inactive]]

Comment on attachment 8914858 [details] [diff] [review]
fix-bug-1403968.patch

Review of attachment 8914858 [details] [diff] [review]:
-----------------------------------------------------------------

I agree with Markus's analysis.

Comment 14

[Nicholas Nethercote [inactive]]

One thing to note: this assertion has been present for months now, so this must be an unusual circumstance.

Comment 15

[Kannan Vijayan [:djvj]]

Comment on attachment 8914149 [details] [diff] [review]
Wrap ProfileBuffer::StreamSamplesToJSON()'s aContext argument in a Maybe<>

Cancelling stale review request.

Comment 16

[Markus Stange [:mstange]]

Yulia, can you still reproduce this? I changed this code a lot in bug 1429904 and those changes might have fixed this bug.

Comment 17

[Markus Stange [:mstange]]

There are two crash reports with moz crash reason "MOZ_RELEASE_ASSERT(aContext)" in the last 6 months:
https://crash-stats.mozilla.com/signature/?product=Firefox&moz_crash_reason=aContext&signature=ProfileBuffer%3A%3AStreamSamplesToJSON&date=%3E%3D2018-01-25T04%3A28%3A57.000Z&date=%3C2018-07-25T07%3A28%3A57.000Z&_columns=date&_columns=product&_columns=version&_columns=build_id&_columns=platform&_columns=reason&_columns=address&_columns=install_time&_sort=-date&page=1

One is from Firefox 58 and one from Firfox 59. Bug 1429904 landed in Firefox 60. So I'm cautiously optimistic that this may in fact be fixed.

Comment 19

[Yulia Startsev [:yulia] OOO until July 2026]

No longer crashes for me :) nice work!

Comment 20

[Markus Stange [:mstange]]

Great! Thanks for testing.