Steps to reproduce:

1. In a tab (I was using about:home), open the web console (Cmd+shift+I).
2. Open a second tab (I loaded about:blank in it).
3. Notice that the CPU use for the Firefox parent process is higher than expected for a process that should be idle, start the profiler.
4. Capture the profile after a few seconds.

Here's the profile I get https://share.firefox.dev/32ouhP9
We have RefreshDriverTick markers at 60Hz, with the reason HasObservers and the URL chrome://devtools/content/webconsole/index.html.

Markus, any idea of what's causing this / how it can be debugged?

I think what we need is a backtrace of when the observer was installed. Maybe we should have another marker, "RefreshObserver", that starts when an observer is registered and stops when it is unregistered, and which has the stack of the registration. Ideally, we'd also have a description of what the observer is for, but that requires pumping more information through the system and auditing and annotating all callers.

Here's an attempt at adding a RefreshObserver marker. I'm not sure if this is good enough to land (hence the feedback request), but it at least gives a stack for the refresh observer that remains even while the tab is in the background, see this example profile: https://share.firefox.dev/2FS5RWX which gives this stack:

(root) []
start [libdyld.dylib]
main [firefox]
XRE_main(int, char**, mozilla::BootstrapConfig const&) [XUL]
XREMain::XRE_main []
XREMain::XRE_main(int, char**, mozilla::BootstrapConfig const&) [XUL]
XREMain::XRE_mainRun() [XUL]
nsAppStartup::Run() [XUL]
nsAppShell::Run() [XUL]
-[NSApplication run] [AppKit]
-[GeckoNSApplication nextEventMatchingMask:untilDate:inMode:dequeue:] []
-[GeckoNSApplication nextEventMatchingMask:untilDate:inMode:dequeue:] [XUL]
-[NSApplication(NSEvent) _nextEventMatchingEventMask:untilDate:inMode:dequeue:] [AppKit]
_DPSNextEvent [AppKit]
_BlockUntilNextEventMatchingListInModeWithFilter [HIToolbox]
ReceiveNextEventCommon [HIToolbox]
RunCurrentEventLoopInMode [HIToolbox]
CFRunLoopRunSpecific [CoreFoundation]
__CFRunLoopRun [CoreFoundation]
__CFRunLoopDoSources0 [CoreFoundation]
__CFRunLoopDoSource0 [CoreFoundation]
__CFRUNLOOP_IS_CALLING_OUT_TO_A_SOURCE0_PERFORM_FUNCTION__ [CoreFoundation]
nsAppShell::ProcessGeckoEvents []
nsAppShell::ProcessGeckoEvents(void*) [XUL]
nsBaseAppShell::NativeEventCallback() [XUL]
NS_ProcessPendingEvents(nsIThread*, unsigned int) [XUL]
nsThread::ProcessNextEvent(bool, bool*) [XUL]
mozilla::detail::RunnableFunction<mozilla::TaskController::InitializeInternal()::$_0>::Run() [XUL]
mozilla::TaskController::ExecuteNextTaskOnlyMainThreadInternal(mozilla::detail::BaseAutoLock<mozilla::Mutex&> const&) [XUL]
mozilla::TaskController::DoExecuteNextTaskOnlyMainThreadInternal(mozilla::detail::BaseAutoLock<mozilla::Mutex&> const&) [XUL]
mozilla::RunnableTask::Run() [XUL]
mozilla::VsyncRefreshDriverTimer::RefreshDriverVsyncObserver::ParentProcessVsyncNotifier::Run() [XUL]
mozilla::VsyncRefreshDriverTimer::RefreshDriverVsyncObserver::NotifyParentProcessVsync() [XUL]
mozilla::VsyncRefreshDriverTimer::RefreshDriverVsyncObserver::TickRefreshDriver(mozilla::layers::BaseTransactionId<mozilla::VsyncIdType>, mozilla::TimeStamp) [XUL]
mozilla::RefreshDriverTimer::Tick(mozilla::layers::BaseTransactionId<mozilla::VsyncIdType>, mozilla::TimeStamp) [XUL]
mozilla::RefreshDriverTimer::TickRefreshDrivers(mozilla::layers::BaseTransactionId<mozilla::VsyncIdType>, mozilla::TimeStamp, nsTArray<RefPtr<nsRefreshDriver> >&) [XUL]
nsRefreshDriver::Tick []
nsRefreshDriver::Tick(mozilla::layers::BaseTransactionId<mozilla::VsyncIdType>, mozilla::TimeStamp) [XUL]
mozilla::dom::ResizeObserverController::Notify() [XUL]
mozilla::dom::ResizeObserverController::BroadcastAllActiveObservations() [XUL]
mozilla::dom::ResizeObserver::BroadcastActiveObservations() [XUL]
ResizeObserverCallback []
void mozilla::dom::ResizeObserverCallback::Call<mozilla::dom::ResizeObserver*>(mozilla::dom::ResizeObserver* const&, mozilla::dom::Sequence<mozilla::OwningNonNull<mozilla::dom::ResizeObserverEntry> > const&, mozilla::dom::ResizeObserver&, mozilla::ErrorResult&, char const*, mozilla::dom::CallbackObject::ExceptionHandling, JS::Realm*) [XUL]
mozilla::dom::ResizeObserverCallback::Call(mozilla::dom::BindingCallContext&, JS::Handle<JS::Value>, mozilla::dom::Sequence<mozilla::OwningNonNull<mozilla::dom::ResizeObserverEntry> > const&, mozilla::dom::ResizeObserver&, mozilla::ErrorResult&) [XUL]
JS::Call(JSContext*, JS::Handle<JS::Value>, JS::Handle<JS::Value>, JS::HandleValueArray const&, JS::MutableHandle<JS::Value>) [XUL]
js::Call(JSContext*, JS::Handle<JS::Value>, JS::Handle<JS::Value>, js::AnyInvokeArgs const&, JS::MutableHandle<JS::Value>, js::CallReason) [XUL]
js::InternalCallOrConstruct(JSContext*, JS::CallArgs const&, js::MaybeConstruct, js::CallReason) [XUL]
js::RunScript []
componentDidMount/this.resizeObserver< [resource://devtools/client/webconsole/components/Input/JSTerm.js:528:47]
CodeMirror</ti/e.exports [chrome://devtools/content/shared/sourceeditor/codemirror/codemirror.bundle.js:1:65505]
Gr [chrome://devtools/content/shared/sourceeditor/codemirror/codemirror.bundle.js:1:60973]
CodeMirror</Gr/< [chrome://devtools/content/shared/sourceeditor/codemirror/codemirror.bundle.js:1:61002]
CodeMirror</Gr/< [chrome://devtools/content/shared/sourceeditor/codemirror/codemirror.bundle.js:1:61376]
js::RunScript(JSContext*, js::RunState&) [XUL]
Interpret(JSContext*, js::RunState&) [XUL]
CodeMirror</Gr/</< [chrome://devtools/content/shared/sourceeditor/codemirror/codemirror.bundle.js:1:61443]
0x3aeaf42f1f84 []
js::jit::InvokeFromInterpreterStub(JSContext*, js::jit::InterpreterStubExitFrameLayout*) [XUL]
js::jit::InvokeFunction(JSContext*, JS::Handle<JSObject*>, bool, bool, unsigned int, JS::Value*, JS::MutableHandle<JS::Value>) [XUL]
js::Call(JSContext*, JS::Handle<JS::Value>, JS::Handle<JS::Value>, js::AnyInvokeArgs const&, JS::MutableHandle<JS::Value>, js::CallReason) [XUL]
js::InternalCallOrConstruct(JSContext*, JS::CallArgs const&, js::MaybeConstruct, js::CallReason) [XUL]
js::RunScript []
Qr [chrome://devtools/content/shared/sourceeditor/codemirror/codemirror.bundle.js:1:63389]
li [chrome://devtools/content/shared/sourceeditor/codemirror/codemirror.bundle.js:1:69948]
On [chrome://devtools/content/shared/sourceeditor/codemirror/codemirror.bundle.js:1:36848]
js::RunScript(JSContext*, js::RunState&) [XUL]
Interpret(JSContext*, js::RunState&) [XUL]
js::GetProperty(JSContext*, JS::Handle<JS::Value>, JS::Handle<js::PropertyName*>, JS::MutableHandle<JS::Value>) [XUL]
js::NativeGetProperty(JSContext*, JS::Handle<js::NativeObject*>, JS::Handle<JS::Value>, JS::Handle<JS::PropertyKey>, JS::MutableHandle<JS::Value>) [XUL]
js::CallGetter(JSContext*, JS::Handle<JS::Value>, JS::Handle<JS::Value>, JS::MutableHandle<JS::Value>) [XUL]
js::InternalCallOrConstruct(JSContext*, JS::CallArgs const&, js::MaybeConstruct, js::CallReason) [XUL]
bool mozilla::dom::binding_detail::GenericGetter<mozilla::dom::binding_detail::NormalThisPolicy, mozilla::dom::binding_detail::ThrowExceptions>(JSContext*, unsigned int, JS::Value*) [XUL]
get Element.clientWidth []
mozilla::dom::Element::GetClientAreaRect() [XUL]
mozilla::dom::Element::GetScrollFrame(nsIFrame**, mozilla::FlushType) [XUL]
mozilla::dom::Document::FlushPendingNotifications(mozilla::ChangesToFlush) [XUL]
PresShell::DoFlushPendingNotifications Layout []
mozilla::PresShell::DoFlushPendingNotifications(mozilla::ChangesToFlush) [XUL]
mozilla::RestyleManager::DoProcessPendingRestyles(mozilla::ServoTraversalFlags) [XUL]
Style computation []
mozilla::ServoStyleSet::StyleDocument(mozilla::ServoTraversalFlags) [XUL]
Servo_TraverseSubtree [XUL]
geckoservo::glue::traverse_subtree [XUL]
style::driver::traverse_dom [XUL]
core::ptr::drop_in_place [XUL]
core::ptr::drop_in_place [XUL]
<style::context::SequentialTaskList<E> as core::ops::drop::Drop>::drop [XUL]
style::context::SequentialTask<E>::execute [XUL]
<style::gecko::wrapper::GeckoElement as style::dom::TElement>::update_animations [XUL]
Gecko_UpdateAnimations [XUL]
nsAnimationManager::UpdateAnimations(mozilla::dom::Element*, mozilla::PseudoStyleType, mozilla::ComputedStyle const*) [XUL]
nsAnimationManager::DoUpdateAnimations(mozilla::NonOwningAnimationTarget const&, nsStyleDisplay const&, ServoCSSAnimationBuilder&) [XUL]
mozilla::dom::Animation::SetTimelineNoUpdate(mozilla::dom::AnimationTimeline*) [XUL]
mozilla::dom::DocumentTimeline::NotifyAnimationUpdated(mozilla::dom::Animation&) [XUL]
nsRefreshDriver::AddRefreshObserver(nsARefreshObserver*, mozilla::FlushType) [XUL]
profiler_capture_backtrace() [XUL]

Do you know who understands the code near the end of this stack?

My go-to person for animations is :hiro.

Nice, sounds like that marker might indeed be useful. Let's keep this bug about the unnecessary refresh ticking and use a different bug for profiler work that would help with tracking down similar issues in the future.

It seems to be caused by the codemirror cursor-blink animation, which is running even when the web console text field is not focused.
I found this animation by inspecting the devtools using the browser toolbox. I had to go into the chrome://devtools/content/webconsole/index.html iframe before the animation would show up in the inspector's Animations panel. The page URL field in the profiler marker's tooltip was very valuable here.

The .Codemirror-cursor element with the opacity animation is a child element of a .CodeMirror-cursors element which has visibility:hidden.
This animation is running in the web console document, which is in an <iframe> which is in a <browser> which is in a background tab panel in the browser.xhtml document, in the parent process. I guess our heuristics to throttle refresh ticks for OMTA-able animations don't cover this case?

Maybe the tab switcher should de-activate the docshells of the devtools browser for background tabs as well, not just the docshells of the regular tab browser?

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

Maybe the tab switcher should de-activate the docshells of the devtools browser for background tabs as well, not just the docshells of the regular tab browser?

We could probably do this from devtools, either here:
https://searchfox.org/mozilla-central/source/devtools/client/framework/devtools-browser.js#747
Or there:
https://searchfox.org/mozilla-central/source/devtools/client/framework/toolbox-hosts.js
Toolbox-hosts.js is probably a good place as this is where we create and manage the topmost devtools's iframe.

Yeah, we should de-activate the devtools' docshell if it's in background. That said, the .Codemirror-cursor animation is properly optimized because as Markus is mentioning in comment 5, it's in visibility:hidden subtree. Properly optimized means skipping styling for the animation, not stopping observing the refresh driver.

Note that even if an animation's target element is out of view or in visibility:hidden subtree, the refresh driver needs to keep ticking due to firing various animation events.

(In reply to Hiroyuki Ikezoe (:hiro) from comment #8)

Properly optimized means skipping styling for the animation, not stopping observing the refresh driver.

Ah, of course. Thanks for clarifying!

It sounds like there's a clear plan of action now in this bug.

Comment on attachment 9176828 [details] [diff] [review]
add RefreshObserver markers

A modified version of this patch landed in bug 1666617.

(In reply to Hiroyuki Ikezoe (:hiro) from comment #8)

Yeah, we should de-activate the devtools' docshell if it's in background.

I agree that this would be worth doing eventually.

the .Codemirror-cursor animation is properly optimized because as Markus is mentioning in comment 5, it's in visibility:hidden subtree.

Replacing the visibility: hidden with a display: none seems like a good idea to me, as it stops the animation not only when devtools is in a background tab, but also when devtools are visible but the focus isn't in the editor.

https://hg.mozilla.org/mozilla-central/rev/2c0576311bcb