Closed Bug 1689215 Opened 4 years ago Closed 3 years ago

20% CPU overhead in the native event loop from CA::Transaction::observer_callback(__CFRunLoopObserver*, unsigned long, void*)

Categories

(Core :: Widget: Cocoa, defect, P2)

defect

Tracking

()

RESOLVED DUPLICATE of bug 1690687
Performance Impact medium

People

(Reporter: whimboo, Unassigned)

References

(Blocks 2 open bugs)

Details

(Keywords: perf:resource-use, power, Whiteboard: [mac:power])

Mozilla/5.0 (Macintosh; Intel Mac OS X 10.16; rv:86.0) Gecko/20100101 Firefox/86.0 ID:20210122212755

I have an around 20% base CPU usage in both Nightly and DevEdition when doing nothing in Firefox. It only drops when I minimize all the browser windows. An instruments session revealed that lots of time is spend in CA::Transaction::observer_callback() which runs within the MainThread of the parent process.

The instruments profile can be found here:
https://www.dropbox.com/sh/g3kqdzr6ew20zk2/AADFfk8ofeCbBR-min-wHUCaa?dl=0

Markus, could you please have a look? Thanks

Flags: needinfo?(mstange.moz)

There are two problems here:

  1. Something is waking up the event loop repeatedly, e.g. some Gecko Runnables are dispatched to the main thread. This should not happen when the browser is idle.
  2. CoreAnimation thinks there is work to do and sends transaction commits to the window server even though probably nothing has changed.

For 1., a new profile from a recent Nightly may shed some light because it has new Runnable markers. For 2, I think we need to debug CoreAnimation itself and see where the "something changed" flags get set and cleared.

Flags: needinfo?(mstange.moz)

I'll have a look to get a profile for 1).

Flags: needinfo?(hskupin)
Blocks: 1683300
Blocks: 1690669

Let's use this bug for 2, and move 1 to bug 1690673.

Flags: needinfo?(hskupin)
Summary: 20% CPU load on main process due to CA::Transaction::observer_callback(__CFRunLoopObserver*, unsigned long, void*) → 20% CPU overhead in the native event loop from CA::Transaction::observer_callback(__CFRunLoopObserver*, unsigned long, void*)

Bug 1690669 has STR to trigger this state artificially.

The time we spend in this function seems to depend on the number of windows that are open.

Profile with two windows: https://share.firefox.dev/2Mxh7vp
Profile with six windows: https://share.firefox.dev/2YFEghw

Severity: -- → S2
Priority: -- → P2
Whiteboard: [qf] → [qf:p2:resources]

Markus, not sure if a real profile is still needed or not, but here is one: https://share.firefox.dev/2OM7edZ

I just noticed that behavior and as it looks like there are also a lot of PCompositorBridge::Msg_DidComposite Runnables dispatched to the main thread of the parent process. Maybe that is needed given that WebRender runs on the main process. But might it be somewhat related to bug 1690621?

Flags: needinfo?(mstange.moz)

(In reply to Henrik Skupin (:whimboo) [⌚️UTC+1] from comment #5)

Markus, not sure if a real profile is still needed or not, but here is one: https://share.firefox.dev/2OM7edZ

No need, the profiles in comment 4 are enough.

I just noticed that behavior and as it looks like there are also a lot of PCompositorBridge::Msg_DidComposite Runnables dispatched to the main thread of the parent process. Maybe that is needed given that WebRender runs on the main process. But might it be somewhat related to bug 1690621?

Yes, DidComposite is bug 1690621.

Flags: needinfo?(mstange.moz)

Markus, I can see that this function is called a lot for me for the parent process all the time. System CPU never drops below 6%.

This bug is marked as P2, do you have any estimate when there will be free cycles to get this bug investigated / fixed? Maybe someone else can help?

Flags: needinfo?(mstange.moz)

I don't have an estimate at the moment. Anybody who has free cycles is welcome to pick up this bug.
I'll ask Brad if he's interested to work on this once he's done with bug 1653417.

However, if you can see CA::Transaction::observer_callback running all the time, even when no animation is going on, then the bigger problem is that we're waking up the thread at all. Fixing this bug won't help with that.

Flags: needinfo?(mstange.moz)

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

However, if you can see CA::Transaction::observer_callback running all the time, even when no animation is going on, then the bigger problem is that we're waking up the thread at all. Fixing this bug won't help with that.

Yes, that's what I see. Does it mean that this is exactly the situation from bug 1690673? See comment 3.

Flags: needinfo?(mstange.moz)

If the profiles show continuous compositing, then yes, that would be bug 1690673.

Flags: needinfo?(mstange.moz)
Whiteboard: [qf:p2:resources] → [qf:p2:resources][mac:power]
Whiteboard: [qf:p2:resources][mac:power] → [qf:p2:resource][mac:power]
Performance Impact: --- → P2
Whiteboard: [qf:p2:resource][mac:power] → [mac:power]

This was fixed by bug 1690687.

Status: NEW → RESOLVED
Closed: 3 years ago
Resolution: --- → DUPLICATE
You need to log in before you can comment on or make changes to this bug.