1946039 - A lot of time spent initializing large buffers in profiler_capture_backtrace

Status: NEW

(Core :: Gecko Profiler, defect, P2)

Description

[Nicolas Silva [:nical]]

I see a lot of time spent on the main thread under profiler_capture_backtrace For example here is a profile of one of the motionmark tests: https://share.firefox.dev/4aLSEZT

It occupies so much of the total CPU time on the main thread that it makes investigating frame pacing issues with the profiler impossible.

Looking at what the code is doing, I think that we should be able to get away with allocating these large buffers without zeroing them. Surely some of the overhead will shift to the time when backtraces are written into the buffer, but removing even just a portion of the cost of collecting these backtraces would be very welcome.

Comment 1

[Florian Quèze [:florian]]

(In reply to Nicolas Silva [:nical] from comment #0)

It occupies so much of the total CPU time on the main thread that it makes investigating frame pacing issues with the profiler impossible.

If the marker stacks are not required for your investigation, you can workaround the issue with the "No Marker Stacks" feature in about:profiling.

Comment 2

[Nicolas Silva [:nical]]

Oddly, I get this very consistently when profiling Nightly, but not with my own builds of Firefox.

Comment 3

[Florian Quèze [:florian]]

(In reply to Nicolas Silva [:nical] from comment #0)

https://share.firefox.dev/4aLSEZT

The profiler overhead is even higher in this profile than what it looks like from the colors of the activity graph as AutoProfilerTextMarker::~AutoProfilerTextMarker is missing a label with the PROFILER category, so that part is colored in grey.

Comment 4

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

We tried to / will try to tackle this issue in Bug 1811807. But it might be good to keep this bug around still for the point you made here:

Looking at what the code is doing, I think that we should be able to get away with allocating these large buffers without zeroing them. Surely some of the overhead will shift to the time when backtraces are written into the buffer, but removing even just a portion of the cost of collecting these backtraces would be very welcome.

(In reply to Florian Quèze [:florian] from comment #3)

(In reply to Nicolas Silva [:nical] from comment #0)

https://share.firefox.dev/4aLSEZT

The profiler overhead is even higher in this profile than what it looks like from the colors of the activity graph as AutoProfilerTextMarker::~AutoProfilerTextMarker is missing a label with the PROFILER category, so that part is colored in grey.

That's interesting. We actually have a label in AutoProfilerTextMarker::~AutoProfilerTextMarker, here. But these extra stacks that don't belong to the profiler category are actually happening during the destruction of AutoProfilerTextMarker member variable, MarkerOptions and MarkerStack. It looks like the best place we can put a label is either ProfileChunkedBuffer::~ProfileChunkedBuffer or ProfileChunkedBuffer::ResetChunkManager.