1441689 - When collecting stacks for the profiler, include line + column information for JIT frames

Status: RESOLVED FIXED

(Core :: JavaScript Engine, enhancement, P3)

Description

[Markus Stange [:mstange]]

It would be nice to know which line of a JS function was executing at any given time. We have this information for JS functions that are running in the interpreter, but we don't have it for JIT frames.

At the moment, for JIT frames, we only know at which line the current JS function starts, but not which line is actually executing.

Comment 1

[Markus Stange [:mstange]]

Attachment: Bug 1441689 - Add ProfiledFrameHandle::lookupScriptAndPc.

Review commit: https://reviewboard.mozilla.org/r/223616/diff/#index_header
See other reviews: https://reviewboard.mozilla.org/r/223616/

Comment 2

[Markus Stange [:mstange]]

Attachment: Bug 1441689 - Add line numbers for all JIT frames. Causes crashes, unfortunately.

The crashes happened when ProfiledFrameHandle::lookupScriptAndPc was calling
BaselineScript::approximatePcForNativeAddress on a null baselineScript.
It looks like something has nulled out the JSScript's baselineScript.

Review commit: https://reviewboard.mozilla.org/r/223618/diff/#index_header
See other reviews: https://reviewboard.mozilla.org/r/223618/

Comment 3

[Nicolas B. Pierron [:nbp]]

One of the problem I see is that we are doing code relocation with LICM, or share pieces of code with GVN, but we should have a non-precise form of this information at least stored in snapshots.

Comment 4

[Markus Stange [:mstange]]

The Firefox profiler is now adding a built-in source view, and will display this type of information for C++ code. It would be great to have the same information for JavaScript code.

Comment 5

[Nicolas B. Pierron [:nbp]]

Thanks Markus for the link with C++ / Rust examples, these are awesome!

One thing I noticed with the crashing patch, is that the RootedScript is assumed to be non-null. While this might be frequently the case this is not guaranteed, for multiple reasons:

• We have trampoline functions, which are C++/JIT calls wrapper to convert from the system ABI to an ABI which makes things easy for the GC.
• We have shared Inline Caches, which might not be associated with a script.
• We have WebAssembly, which does not use JSScript.

I think the JS team can find someone to help design a proper API which can be used by the Gecko Profiler.
I will raise this topic in our next SpiderMonkey meeting.

Comment 6

[Markus Stange [:mstange]]

Thanks, Nicolas!

Comment 7

[Nicolas B. Pierron [:nbp]]

The lasted patches bit-rot since the last time. However, I have a few comments to revive the current set of patches.

The current patches are adding ProfiledFrameHandle::lookupScriptAndPc, or renaming an existing function to this new name. Since the function got removed,as some clean-up went by. This is not a big deal, the js::jit::JitcodeGlobalEntry still has the information provided by js::jit::JitcodeGlobalEntry::callStackAtAddr. The second patch adds a way to query the ProfiledFrameHandle using lookupScriptAndPc, but this is no longer an option, as the function got removed.

One thing to note is how the ProfiledFrameEntry aJITFrame flows into StreamJITFrame. StreamJITFrame is called by JSONForJITFrame and JitFrameInfo::AddInfoForRange, which iterates over the ProfiledFrameEntry. As a result of iterating over the ProfiledFrameRange returned by JS::GetProfiledFrames.

The remarkable point, is that JS::GetProfiledFrames calls the other overload of js::jit::JitcodeGlobalEntry::callStackAtAddr.

callStackAtAddr has 2 definitions:

• A first definition with an out-param to return the BytecodeLocationVector, which is what we are interested in to get the line information.
• A second definition with an out-param to return the names of the functions, which is what JS::GetProfiledFrames returns.

To rebase the patches, a simple fix might be to change the ProfiledFrameRange to hold a BytecodeLocationVector, as well as adding a BytecodeLocation field to the ProfiledFrameEntry.

Then we should be able to query the line number in StreamJITFrame using the aJITFrame argument.

This does not tell us whether the same crash will occur or not, but this should reduce the risk as we will no longer be doing an extra lookup.
Later on, we might want to merge both callStackAtAddr with 2 out-param.

Comment 8

[Nicolas B. Pierron [:nbp]]

One thing to note, is that the BytecodeLocation carry some information which might be useful for JS Engine developers, which is the opcode which is executed. While most of these would be calls, it might be interesting to distinguish the opcode in the profiler.

Comment 9

[Markus Stange [:mstange]]

This all sounds great!

Comment 10

[Nicolas B. Pierron [:nbp]]

Attachment: Bug 1441689 - Instrument ProfiledFrameHandle to fetch line number information. r=

This patch changes the function callStackAtAddr to output both the Bytecode
location as well as the associated Script pointer. Unfortunately, we cannot use
the BytecodeLocation abstraction as it is link to too many other parts of the
JavaScript engine that we prefer not to expose.

With this modification, we are now able to annotate JIT frame within the
profiler, with line number information. The line number information can later be
used by the profiler interface to display the associated code.

Comment 11

[Nicolas B. Pierron [:nbp]]

I had local failures locally which did not seem related to the profiler. Thus, I pushed the new patch to try.

There are failures which are suggesting a follow-up issue related to AddJitInfoForRange.

Comment 12

[Markus Stange [:mstange]]

What's the next step here? Pushing to try again and debugging the failures?

Comment 13

[Nicolas B. Pierron [:nbp]]

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

What's the next step here? Pushing to try again and debugging the failures?

Ideally someone from the profiler team should resume working on this feature, on top of the patch I rebased, fixing the issues which are remaining in the Profiler.

Comment 14

[Markus Stange [:mstange]]

Bug 1969435 removed the script pointer from the table entry, but I think we'll need it to map the pc to the right line.

Comment 15

[Markus Stange [:mstange]]

Nazim recently landed bug 1979114. If you go to about:profiling and enable the "JS Sources" feature, you can now have a working JS source view when you capture profiles in Firefox.

However, double-clicking a JS function often opens the source view at the wrong spot, and the per-line sample counts are incorrect, due to this bug. So now would be a great time to look into this bug again. Nazim has a patch which undoes some of bug 1969435 and which gives us some line information, but the information we get doesn't seem very accurate, so more investigation is needed.

Comment 16

[Nazım Can Altınova [:canova][:canaltinova on phabricator]]

Attachment: Bug 1441689 - Add line and column information to the JIT frames r?iain!,mstange!

Comment 17

[Nazım Can Altınova [:canova][:canaltinova on phabricator]]

Attachment: Bug 1441689 - Add JSScript back to IonEntry/BaselineEntry r?iain

This patch does a partial backout of https://phabricator.services.mozilla.com/D255393
because we removed the JSScript at first thinking that we don't need it
while we are profiling. But we need it to be able to get the line and
column information for JIT frames. See the following patch to see how we
use the JSScript inside callStackAtAddr.

It looks like there is another way to get this line/column information
which is using utilizing the data that we keep for PerfSpewer. But
unfortunately that doesn't work well for us for now because PerfSpewer
doesn't know about the inlined JIT frames. If we add this information to
PerfSpewer, then we can potentially revert this patch again. But I would
like to work on this iteratively, by having this information first, and
then improving it later.

Comment 18

[Nazım Can Altınova [:canova][:canaltinova on phabricator]]

Attachment: Bug 1441689 - Keep a copy of CallStackFrameInfo directly in ProfiledFrameHandle r?iain

Previously we were keeping the fields of CallStackFrameInfo one by one
in the ProfiledFrameHandle. But since we added this struct now, we can
simply pass it and keep it around instead. This is going to be useful
when we add more values to this struct like the line and column number.

Comment 19

[Nazım Can Altınova [:canova][:canaltinova on phabricator]]

Attachment: Bug 1441689 - Record baseline call sites properly when profiling is enabled r?iain,jandem,mstange

In some cases, baseline frame line numbers were attributed to either
loop head or the function signature because the profiler had no valid
recorded return address once baseline jumped into IC/native stubs, so
JSJitProfilingFrameIterator fell back to an earlier point in the
JSScript while stackwalking.

Note that ion already avoids this by enabling
masm.enableProfilingInstrumentation() and wrapping every call with the
profiler RAII helper. This patch does the same for baseline:

• It turns on masm.enableProfilingInstrumentation() whenever we generate
  baseline code while the Gecko profiler is enabled.
• Introduces emitProfilerCallSiteInstrumentation() and calls it before
  every baseline JS call opcode so each masm.call records its return
  address. This is a bit different compared to ion (calls masm.callJit
  which handles the profiler call site directly), because it wasn't as
  straightforward as ion to convert masm.call calls into callJit. Also,
  even though that method uses an RAII class, weirdly it doesn't
  actually have anything in its destructor. That's why it's fine to use
  it this way.
• Exposes a MacroAssembler::instrumentProfilerCallSite() helper so we
  can still instrument the profiler call site from baseline.
• Switches baseline’s VM calls to callJit so they too update
  lastProfilingCallSite.

With these changes, the sampler always lands on a real baseline return
address, the existing RetAddr table can map it back to the correct
pc/line, and profiler listings show the actual call site instead of the
top of the function.

I'm adding a test in the following patches as it requires some changes
in the shell.

Comment 20

[Nazım Can Altınova [:canova][:canaltinova on phabricator]]

Attachment: Bug 1441689 - Include line and column number to the frames inside readGeckoProfilingStack r?iain,jandem

This patch adds line and column number information to the frames in the
return object of readGeckoProfilingStack JS shell function. It will be
needed in the next commit for writing a test for it.

Comment 21

[Nazım Can Altınova [:canova][:canaltinova on phabricator]]

Attachment: Bug 1441689 - Add profiler jit-test for JS frame line numbers r?iain,jandem

Now that we have fixed the profiler JIT line number attribution
properly, let's add a test to verify this.

This patch simulates the failure case that I was experiencing with the
baseline frames in one of my demo websites. The failure case had a
for-of loop and had a 3-4 calls inside of it that calls different DOM
APIs etc. The line numbers for all of these calls inside the for loop
were attributed to the for loop header itself, assuming because we had
profiler call sites emitted for iterator .next, but not for the others.

This test was failing before my commit that fixes the baseline profiler
call sites.

Comment 22

[Nazım Can Altınova [:canova][:canaltinova on phabricator]]

Attachment: Bug 1441689 - Remove unused trace methods from the profiler JIT entries r?iain

It appears that we've removed the definitions of these methods and uses
of them, but not the declarations. This patch removes these too.

Comment 23

[Nazım Can Altınova [:canova][:canaltinova on phabricator]]

Attachment: Bug 1441689 - Store SharedImmutableScriptData inside IonEntry r?iain

This patch introduces IonScriptData, which holds both
ScriptSourceAndExtent and RefPtr<SharedImmutableScriptData>, and stores
it inside IonEntry. This is needed for later patches, where we will use
it to fetch line and column number information from Ion entries instead
of keeping a reference to JSScript.

Note that we don’t need a reference to SharedImmutableScriptData for
BaselineEntry, because we will be using PerfSpewer directly for those
entries. It’s not possible to use PerfSpewer for IonEntry yet, as it
does not support inline frames. Ideally, we should add inline frame
support and then remove the SharedImmutableScriptData RefPtr from this
entry in the future.

Comment 24

[Nazım Can Altınova [:canova][:canaltinova on phabricator]]

Attachment: Bug 1441689 - Add JitCodeAPI back to PerfSpewer r?iain,denispal

This partially reverts commit b62582b (D226645) and removes some unused
parts of it with minor code changes.

This API will be used by the profiler in the later patches to fetch the
line and column numbers for the JIT frames.

Co-authored-by: Denis Palmeiro <[e-mail]>

Comment 25

[Nazım Can Altınova [:canova][:canaltinova on phabricator]]

Attachment: Bug 1441689 - Skip consecutive PerfSpewer profiler source entries with the same line/column r?iain,denispal

This reduces the memory usage of the PerfSpewer profiler source entries
and improves the binary search performance at the same time.

From my very scientific(?) testing, it reduces the memory usage of
the source entries by ~70%.

Comment 26

[Nazım Can Altınova [:canova][:canaltinova on phabricator]]

Attachment: Bug 1441689 - Add some more allocation failure checks inside PerfSpewer r?denispal!

I noticed that sometimes some jit-tests were failing in CI because we
weren't handling the OOM cases here. After these changes, jit-tests
pass as expected.

Comment 27

[Pulsebot]

Pushed by [e-mail]:
https://github.com/mozilla-firefox/firefox/commit/fe6c27104d41
https://hg.mozilla.org/integration/autoland/rev/e4c3b67fc43b
Remove unused trace methods from the profiler JIT entries r=iain
https://github.com/mozilla-firefox/firefox/commit/26eae69048b5
https://hg.mozilla.org/integration/autoland/rev/697e151de33a
Store SharedImmutableScriptData inside IonEntry r=iain
https://github.com/mozilla-firefox/firefox/commit/48927e737ffe
https://hg.mozilla.org/integration/autoland/rev/193974dd6345
Keep a copy of CallStackFrameInfo directly in ProfiledFrameHandle r=iain
https://github.com/mozilla-firefox/firefox/commit/c1d433543c42
https://hg.mozilla.org/integration/autoland/rev/b90791a48225
Add JitCodeAPI back to PerfSpewer r=denispal
https://github.com/mozilla-firefox/firefox/commit/e380b5c506a9
https://hg.mozilla.org/integration/autoland/rev/9d82bc0dea6c
Add some more allocation failure checks inside PerfSpewer r=denispal
https://github.com/mozilla-firefox/firefox/commit/e18c28d34f5b
https://hg.mozilla.org/integration/autoland/rev/944638f1b847
Skip consecutive PerfSpewer profiler source entries with the same line/column r=denispal
https://github.com/mozilla-firefox/firefox/commit/13b125d99e32
https://hg.mozilla.org/integration/autoland/rev/6115a42a42fb
Add line and column information to the JIT frames r=iain,mstange,profiler-reviewers
https://github.com/mozilla-firefox/firefox/commit/6f7efa870c08
https://hg.mozilla.org/integration/autoland/rev/538dc5281c12
Record baseline call sites properly when profiling is enabled r=iain
https://github.com/mozilla-firefox/firefox/commit/9b4b2c36dcb7
https://hg.mozilla.org/integration/autoland/rev/2bde7647ac31
Include line and column number to the frames inside readGeckoProfilingStack r=iain
https://github.com/mozilla-firefox/firefox/commit/06f464569586
https://hg.mozilla.org/integration/autoland/rev/00baf6513522
Add profiler jit-test for JS frame line numbers r=iain

Comment 28

[Pulsebot]

Pushed by [e-mail]:
https://github.com/mozilla-firefox/firefox/commit/9435470d8350
https://hg.mozilla.org/integration/autoland/rev/4b2fd156db41
Revert "Bug 1441689 - Add profiler jit-test for JS frame line numbers r=iain" for causing leaks at js_pod_arena_malloc.

Comment 29

[Atila Butkovits]

Backed out for causing leaks at js_pod_arena_malloc.

Backout link: https://hg.mozilla.org/integration/autoland/rev/4b2fd156db417b2726ccd2e8e313f82dc74f7a5b

Push with failures: https://treeherder.mozilla.org/jobs?repo=autoland&resultStatus=testfailed%2Cbusted%2Cexception%2Cretry%2Cusercancel&revision=d83a8a389a1ed1d53f17b9cb24b76cc58c40e68c&selectedTaskRun=Qk2nwqXLRlG2d-Sv0_WScg.0

Failure log: https://treeherder.mozilla.org/logviewer?job_id=543748812&repo=autoland&task=Qk2nwqXLRlG2d-Sv0_WScg.0&lineNumber=8940

Comment 30

[Nazım Can Altınova [:canova][:canaltinova on phabricator]]

Attachment: Bug 1441689 - Explicitly free PerfSpewer heap allocations r?denispal!,nbp!

I got a memory leak on some profiler tests after I started to use
PerfSpewer inside the profiler codebase.

It appears that the PerfSpewer objects are mostly allocated using a Lifo
allocator, and their destructors don't run because of this. Using the
system allocator inside an object allocated with a lifo allocator was
essentially causing a memory leak for the objects that were created with
the system allocator because their memory needs to be handled
explicitly by freeing them.

Instead of system allocator, this patch uses LifoAlloc for all the
allocated objects that are inside PerfSpewer.

Comment 31

[Pulsebot]

Pushed by [e-mail]:
https://github.com/mozilla-firefox/firefox/commit/8944cec6b22f
https://hg.mozilla.org/integration/autoland/rev/261db6e0a49b
Remove unused trace methods from the profiler JIT entries r=iain
https://github.com/mozilla-firefox/firefox/commit/969175db70e8
https://hg.mozilla.org/integration/autoland/rev/dc2fe4b5559b
Store SharedImmutableScriptData inside IonEntry r=iain
https://github.com/mozilla-firefox/firefox/commit/650b0f3acc3d
https://hg.mozilla.org/integration/autoland/rev/16a7d61f77fc
Keep a copy of CallStackFrameInfo directly in ProfiledFrameHandle r=iain
https://github.com/mozilla-firefox/firefox/commit/c3dcd5647bd6
https://hg.mozilla.org/integration/autoland/rev/35d56c4a23aa
Add JitCodeAPI back to PerfSpewer r=denispal
https://github.com/mozilla-firefox/firefox/commit/c39398ba6762
https://hg.mozilla.org/integration/autoland/rev/6662163e154a
Add some more allocation failure checks inside PerfSpewer r=denispal
https://github.com/mozilla-firefox/firefox/commit/c1329091a3ff
https://hg.mozilla.org/integration/autoland/rev/f801c0f9aad7
Explicitly free PerfSpewer heap allocations r=denispal,nbp
https://github.com/mozilla-firefox/firefox/commit/a73e66c1574b
https://hg.mozilla.org/integration/autoland/rev/7331db6f0682
Skip consecutive PerfSpewer profiler source entries with the same line/column r=denispal
https://github.com/mozilla-firefox/firefox/commit/f62547f0308c
https://hg.mozilla.org/integration/autoland/rev/093475c22347
Add line and column information to the JIT frames r=iain,mstange,profiler-reviewers
https://github.com/mozilla-firefox/firefox/commit/bb1a07c1ff05
https://hg.mozilla.org/integration/autoland/rev/8db3637cf8c9
Record baseline call sites properly when profiling is enabled r=iain
https://github.com/mozilla-firefox/firefox/commit/6b32c40ca499
https://hg.mozilla.org/integration/autoland/rev/011e66d46bfd
Include line and column number to the frames inside readGeckoProfilingStack r=iain
https://github.com/mozilla-firefox/firefox/commit/23022df23a15
https://hg.mozilla.org/integration/autoland/rev/c879ccfd1702
Add profiler jit-test for JS frame line numbers r=iain

Comment 32

[Serban Stanca [:SerbanS]]

https://hg.mozilla.org/mozilla-central/rev/261db6e0a49b
https://hg.mozilla.org/mozilla-central/rev/dc2fe4b5559b
https://hg.mozilla.org/mozilla-central/rev/16a7d61f77fc
https://hg.mozilla.org/mozilla-central/rev/35d56c4a23aa
https://hg.mozilla.org/mozilla-central/rev/6662163e154a
https://hg.mozilla.org/mozilla-central/rev/f801c0f9aad7
https://hg.mozilla.org/mozilla-central/rev/7331db6f0682
https://hg.mozilla.org/mozilla-central/rev/093475c22347
https://hg.mozilla.org/mozilla-central/rev/8db3637cf8c9
https://hg.mozilla.org/mozilla-central/rev/011e66d46bfd
https://hg.mozilla.org/mozilla-central/rev/c879ccfd1702

Comment 33

[Pulsebot]

Pushed by [e-mail]:
https://github.com/mozilla-firefox/firefox/commit/98075fa18c1f
https://hg.mozilla.org/integration/autoland/rev/292320f4a2f7
Revert "Bug 1441689 - Add profiler jit-test for JS frame line numbers r=iain" for causing Bug 2012244

Comment 34

[Cristina Horotan [:chorotan]]

Backed out on request for causing https://bugzilla.mozilla.org/show_bug.cgi?id=2012244

https://hg.mozilla.org/integration/autoland/rev/292320f4a2f72a12ccc954e7e71fb7b88fc13686

Comment 35

[Pulsebot]

Pushed by [e-mail]:
https://github.com/mozilla-firefox/firefox/commit/30b3bad520e4
https://hg.mozilla.org/integration/autoland/rev/3f967d6e031c
Remove unused trace methods from the profiler JIT entries r=iain
https://github.com/mozilla-firefox/firefox/commit/2af0bdc73da0
https://hg.mozilla.org/integration/autoland/rev/04eb44addd8d
Store SharedImmutableScriptData inside IonEntry r=iain
https://github.com/mozilla-firefox/firefox/commit/429e1d144b2d
https://hg.mozilla.org/integration/autoland/rev/3756372b4877
Keep a copy of CallStackFrameInfo directly in ProfiledFrameHandle r=iain
https://github.com/mozilla-firefox/firefox/commit/031036eafd79
https://hg.mozilla.org/integration/autoland/rev/7a5e006b184c
Add JitCodeAPI back to PerfSpewer r=denispal
https://github.com/mozilla-firefox/firefox/commit/d4f86372aac9
https://hg.mozilla.org/integration/autoland/rev/780d089dd9dc
Add some more allocation failure checks inside PerfSpewer r=denispal
https://github.com/mozilla-firefox/firefox/commit/b7dcfffb2877
https://hg.mozilla.org/integration/autoland/rev/75c72ea59c71
Explicitly free PerfSpewer heap allocations r=denispal,nbp
https://github.com/mozilla-firefox/firefox/commit/d8d84acecf7b
https://hg.mozilla.org/integration/autoland/rev/24027d1285d0
Skip consecutive PerfSpewer profiler source entries with the same line/column r=denispal
https://github.com/mozilla-firefox/firefox/commit/da1d6c8a503a
https://hg.mozilla.org/integration/autoland/rev/224a75d71e2a
Add line and column information to the JIT frames r=iain,mstange,profiler-reviewers
https://github.com/mozilla-firefox/firefox/commit/be4dc54af2dd
https://hg.mozilla.org/integration/autoland/rev/87a65876bd9a
Record baseline call sites properly when profiling is enabled r=iain
https://github.com/mozilla-firefox/firefox/commit/0d51366d8f8f
https://hg.mozilla.org/integration/autoland/rev/7a2d9442ccd0
Include line and column number to the frames inside readGeckoProfilingStack r=iain
https://github.com/mozilla-firefox/firefox/commit/8329f90a8c8b
https://hg.mozilla.org/integration/autoland/rev/fe715578792e
Add profiler jit-test for JS frame line numbers r=iain

Comment 36

[Cosmin Sabou [:CosminS]]

https://hg.mozilla.org/mozilla-central/rev/3f967d6e031c
https://hg.mozilla.org/mozilla-central/rev/04eb44addd8d
https://hg.mozilla.org/mozilla-central/rev/3756372b4877
https://hg.mozilla.org/mozilla-central/rev/7a5e006b184c
https://hg.mozilla.org/mozilla-central/rev/780d089dd9dc
https://hg.mozilla.org/mozilla-central/rev/75c72ea59c71
https://hg.mozilla.org/mozilla-central/rev/24027d1285d0
https://hg.mozilla.org/mozilla-central/rev/224a75d71e2a
https://hg.mozilla.org/mozilla-central/rev/87a65876bd9a
https://hg.mozilla.org/mozilla-central/rev/7a2d9442ccd0
https://hg.mozilla.org/mozilla-central/rev/fe715578792e