Open Bug 1280802 Opened 8 years ago Updated 2 years ago

Angular framework performance test spends 10% in nursery GC

Categories

(Core :: JavaScript: GC, defect, P3)

defect

Tracking

()

Performance Impact low
Tracking Status
firefox50 --- affected

People

(Reporter: till, Unassigned)

References

(Blocks 2 open bugs)

Details

(Keywords: perf)

Attachments

(3 files)

Running the Angular part of [1], I see a lot of time spent under js::Nursery::Collect - roughly 10%, reliably on each run. That seems like an awfully long time for nursery collections. Looking at what triggers the GCs, it seems like event dispatching is involved.

[1] https://chrisharrington.github.io/demos/performance/
bug 1237058 might be related.
Event dispatch (or setTimeout or animation frame callbacks or Promise callbacks) tend to trigger everything in browser.
I see some minorGCs but nothing there hints event dispatching is causing it.
And profiles do look quite different to bug 1237058 after all.

till, if you have profiles hinting that event dispatching might be causing some issues here, want to upload the profiles somewhere?
Attached file angular-profile.json
> till, if you have profiles hinting that event dispatching might be causing
> some issues here, want to upload the profiles somewhere?

The reason I thought events might be related is because in a profile using the built-in profiler, an inverted call tree shows js::Nursery::collect as having EventDispatcher::Dispatch as its most-frequent caller. See the attached profile.

I'm not sure I'm reading the profile right, so I could very well be wrong about the connection.
I'm not familiar using builtin profiler, but if I interpret that right, it is just that there is an event listener for click event, and the listener then just triggers the test to run, so naturally that is where all the minorGCs happen, underneath click event dispatch.

(I use Zoom on linux for profiling, but naturally it doesn't understand JITed JS code more than time is spent there)

Btw, is the profile done using Nightly? If so, with async stacks enabled? They are enabled by default on non-release builds, like Nightly. pref name is javascript.options.asyncstack
Async stacks slow down everything a lot. We really should disable them by default.
(In reply to Olli Pettay [:smaug] (high review load, please consider other reviewers) from comment #4)
> I'm not familiar using builtin profiler, but if I interpret that right, it
> is just that there is an event listener for click event, and the listener
> then just triggers the test to run, so naturally that is where all the
> minorGCs happen, underneath click event dispatch.

That makes sense.

> Btw, is the profile done using Nightly? If so, with async stacks enabled?
> They are enabled by default on non-release builds, like Nightly. pref name
> is javascript.options.asyncstack

I did test with and without; for this particular test it didn't make too much of a difference. See the new profile.

> Async stacks slow down everything a lot. We really should disable them by
> default.

I agree: they're definitely too slow, and it doubtlessly costs us developer mindshare to have them enabled in builds that webdevs (hopefully) use.
Attached image screenshot of profile
Here's a screenshot so others don't need to import the profile themselves.

Till's reading of the profile matches my own: event dispatch seems to be pretty hard on the nursery here.

Regarding async stacks: it would be nice to speed them up and it would also be nice to only use them when devtools are open.
(In reply to Nick Fitzgerald [:fitzgen] [⏰PDT; UTC-7] from comment #6)
> Till's reading of the profile matches my own: event dispatch seems to be
> pretty hard on the nursery here.
Not event dispatch, but stuff under it ;)
Click event just happens to trigger the testcase.
(In reply to Olli Pettay [:smaug] (high review load, please consider other reviewers) from comment #7)
> (In reply to Nick Fitzgerald [:fitzgen] [⏰PDT; UTC-7] from comment #6)
> > Till's reading of the profile matches my own: event dispatch seems to be
> > pretty hard on the nursery here.
> Not event dispatch, but stuff under it ;)
> Click event just happens to trigger the testcase.

Do we have a heuristic where we empty the nursery before/after dispatching an event?

Otherwise, if the stack really does look like this:

  js::Nursery::collect
  ...
  JS event handler function
  EventDispatcher::Dispatch
  ...

Then I would expect to see the JS event handler function's frame to be in between js::Nursery::collect and EventDispatcher::Dispatch.
Whiteboard: [qf:p3]
Keywords: perf
Priority: -- → P3
Blocks: 1507445
Performance Impact: --- → P3
Whiteboard: [qf:p3]
Severity: normal → S3
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Created:
Updated:
Size: