Closed Bug 1698748 Opened 3 years ago Closed 2 years ago

DummyEvent firing at too high rate both in content and parent processes

Categories

(Core :: Gecko Profiler, defect, P2)

Desktop
Linux
defect

Tracking

()

RESOLVED DUPLICATE of bug 1741682

People

(Reporter: julienw, Unassigned)

References

(Blocks 2 open bugs)

Details

(Whiteboard: [fxp])

I captured this in my dev Firefox:
https://share.firefox.dev/3rR7ZBm

You can see DummyEvent Runnable markers on every processes, at high frequency.

In this profile this is latest nightly on Linux X11, right after updating and rebooting it. But I see this reliably whenever I capture a profile.

OS: Unspecified → Linux
Hardware: Unspecified → Desktop
Component: General → Gecko Profiler

The code we are talking about here is https://searchfox.org/mozilla-central/rev/526a5089c61db85d4d43eb0e46edaf1f632e853a/widget/nsBaseAppShell.cpp#274-280

It's been around for a very long time (apparently introduced in 2006 in bug 326273).

Component: Gecko Profiler → Widget

But does it really use any cpu time. It is after all a dummy runnable created for the appshell?

It seems to be firing at a rate of 1000Hz (once every millisecond). Even if it doesn't take any CPU time, waking up the CPU at that rate surely has some power impact.

DummyEvent should be dispatched to the main thread if main thread is already doing work in AppShell.
Why was https://searchfox.org/mozilla-central/rev/526a5089c61db85d4d43eb0e46edaf1f632e853a/widget/nsBaseAppShell.cpp#207,268 called.
Or do we have some regression that we end up somehow treating the main thread empty when the callback is called.
Or does the profiler somehow affect to this?

Something in the profiler is triggering this.
I tested locally by changing the DummyEvent to have a counter how often such runnable runs.
It run never during startup, but immediately when starting the profiler it kept running all the time, I think in all the processes.

Component: Widget → Gecko Profiler
Severity: -- → S3
Priority: -- → P1

Trying to change the profiler interval, the dummy event was dispatched at the same rate.
Profile, with added "DispatchDummyEventMarker": https://share.firefox.dev/3geJ73j

Looking at the sampled stacks, they're all in PollWrapper.
Wild guess: Could the poll be woken up because of the thread sampler periodically sending signals in order to suspend threads?

See Also: → 1724980

I recently was looking at a large (> 100MB) profile JSON which was captured on Linux, and the major contributor to the profile size was the amount of DummyEvent runnable markers.

Depends on: 1741682

P1->P2, because it's not that critical.
It's annoying, and may cause mild confusion at times when people see these repeated dummy events, but it's not spoiling profiles otherwise.
Also, the solution will probably be complex and/or risky (trying to ignore "spurious" wake-ups, at the risk of ignoring a real wake-up that would happen if the profiler was not running), so it may take time to get it right...

Priority: P1 → P2
Status: NEW → RESOLVED
Closed: 2 years ago
Resolution: --- → DUPLICATE

🥳🥳🥳

You need to log in before you can comment on or make changes to this bug.