getFlameGraphTiming is slow

[gregtatum]

STR:

• View this profile.
• Then change the time selection.
• It's really slow.

Here is a recording of that slowness, with getFlameGraphTiming focused.
https://perfht.ml/2p0EXzK

Specifically the call tree method getDisplayData is the culprit in being the most slow. The results are already cached, but I think we need to computer fewer things, or provide another avenue to get that data that isn't so expensive.

[julienw]

The recording is interesting.

When I switch back to "combined view" and then invert the callstack, we see that merely getting an entry from a map in CallTree's getChildren takes 400ms of this profile.

In JS-only view, we see that CallTree's getChildren is also very present. (Note: we don't see it in the "combined" view because of the JIT addresses that mess up the view).

I wonder if, in getFlameGraphTiming, we shouldn't avoid calling getChildren (that's optimized for just getting one node's children) and instead process the callNodeTable directly. I believe one issue is that each time we call getChildren with a new index, we loop over the full callNodeTable. Instead we should loop over the callNodeTable only once. This would move the algorithm from O(n²) to O(n) (if I get my complexity right).

getDisplayData is expensive as well, as you mention. Especially extracting favicons is likely useless for the flame graph view. But I'm confused as I don't see in the code where we call it...

[brisad]

@julienw getDisplayData is not called from the code currently in master. But it is in the PR for flame graph colors: https://github.com/devtools-html/perf.html/pull/809/files#diff-1bd5b469a11285298bff060b35e007cbR69
And as you say, things like favicons aren't used, only formatted strings for the time in the tooltips. It could probably just be extracted to its own method in order to not compute unused data.

The caching used in for the call tree is unfortunately not effective here, since when we change the time selection, completely new call trees are created all the time. And the flame graph needs to recompute its timing structure completely before drawing on the canvas. getChildren is the main culprit for me when I experiment, and I have noted the same complexity issue. Looping only once as you say should really improve things.

[julienw]

Ah yes, thanks @brisad! Definitely you should use a simpler method instead of getDisplayData. In the profile's inverted tree, extractFaviconFromLibname stands out right after getChildren so I think it's a worthwhile optimization.

[brisad]

I've created two PRs for reducing the amount of unnecessary work done, one addressing getDisplayData and one addressing getChildren.

For the example profile, I do notice that things are a bit better, but it is still slow since there's a lot of rebuilding of the flame graph data structure being done.

[julienw]

With these 2 PRs ^ we get a 1 second speed-up when loading my test profile http://localhost:4242/public/280e10708c0660695ef5af145c53179d29d9796c/flame-graph/?react_perf&thread=4&threadOrder=0-2-3-4-5-1&v=3.

@gregtatum can you check with latest master whether this is still slow and recapture a profile if it is?

[julienw]

Some other tools (eg: hotspot) use a "cost threshold" to filter out some nodes. Default in hotspot is 0.10%. Could it be a good option for us?

[brisad]

I took a look at the profile for getFlameGraphTiming again, and saw that there's much time spent setting and getting items from the _children map inside preloadChildrenCache. That function iterates through all the call node indices, and fills in the map for each index, causing the hashing function for the map to be called over and over again.

I realized that since we are using call node indices as keys, we're probably better off using a preallocated array instead. That way we avoid the overhead of the hashing function. And since preloadChildrenCache iterates through all indices, it will be dense and we won't lose space in memory switching to an array instead. (If we don't preload the cache and use getChildren instead, we do, but my guess is that is okay, given the speedup)