Lots of time spend in Window.clearTimeout after watching movies on https://www.tvnow.de
Categories
(Core :: DOM: Core & HTML, enhancement, P3)
Tracking
()
Tracking | Status | |
---|---|---|
firefox78 | --- | verified |
People
(Reporter: whimboo, Assigned: smaug)
References
(Blocks 2 open bugs)
Details
(Keywords: memory-footprint, perf, power)
Attachments
(3 files)
As already noticed over on bug 1578161 a lot of time is spent in Window.clearTimeout
. This is not visible immediately, but after watching some videos on that page. In my case I tried to reproduce it for https://www.tvnow.de/serien/unter-uns-20/2020-02
After watching one of those freely available episodes, and the page forwarded to the next one automatically, I have seen that the CPU was spinning up a lot even with the page not visible and the browser in hidden. Also the memory usage increases a lot.
Here a created profile: https://perfht.ml/37pqsd5
As talking to Olli it looks like the page is creating a lot of timers, which need to be removed again. So this may be a webcompat issue, but for now I'm filing it under DOM.
Reporter | ||
Comment 1•4 years ago
|
||
Speaking about the CPU load it keeps staying at 100% for the specific web content process.
Assignee | ||
Comment 2•4 years ago
|
||
Reporter | ||
Comment 3•4 years ago
|
||
I had it again today. It was actually after waking up the MBP from hibernation. Maybe this mode caused that behavior?
Reporter | ||
Comment 4•4 years ago
|
||
Also I'm using NoScript and switching to temporarily trust all, and immediately revoke it again, fixed it. When I see it the next time I will record a gecko profile while doing these steps.
Updated•4 years ago
|
Reporter | ||
Comment 5•4 years ago
|
||
I hit it today again after I paused the playback and put the tab into background. Not sure when the higher CPU load actually started. Also it was very hard to get the video played again, because clicking the (overlay) play button didn't cause any reaction. Maybe that is due to the higher CPU load and maybe delayed event handling? After several clicks it worked.
(In reply to Henrik Skupin (:whimboo) [⌚️UTC+1] from comment #4)
Also I'm using NoScript and switching to temporarily trust all, and immediately revoke it again, fixed it. When I see it the next time I will record a gecko profile while doing these steps.
It's actually enough to simply reload the page. Then the CPU load will return to a normal level after a couple of seconds.
Also Olli's example testcase above doesn't cause this behavior.
Reporter | ||
Comment 6•4 years ago
|
||
Ok, so this seems to be a timing thing. Over the past two weeks the following steps have been qualified to reproduce the problem:
- Open a new tab and pin it
- Navigate to eg https://www.tvnow.de/serien/unter-uns-20
- Start watching the video and seek close to the end of part 1
- Continue watching and let it switch to part 2
- Pause the playback
- Navigate away and let the tab sit there for one or two hours
At some point you will notice that Firefox consumes 100% CPU load for this tab. In such a situation you will be able to see the massive calls into window.clearTimeout
.
Once you reload the page, and wait some seconds everything is fine again.
Olli, would you have the time to try that? Not sure what else I could do to give more information. Thanks!
Reporter | ||
Comment 7•4 years ago
|
||
Olli, is there anything I can further do to help getting this investigated? Maybe creating a long-term baseline profile with only the markers added so we can see where the setTimeouts are all set? Not sure if that is possible right now.
Assignee | ||
Comment 8•4 years ago
|
||
I'm looking this. Unfortunately out timeout code is rather complicated.
And perhaps the issue is that no one is setting the timers, but some script is calling clearTimeout with invalid id.
Assignee | ||
Updated•4 years ago
|
Assignee | ||
Comment 9•4 years ago
|
||
Assignee | ||
Comment 10•4 years ago
•
|
||
https://treeherder.mozilla.org/#/jobs?repo=try&revision=84b198aadb81d04cb3cb328d8a99dd755d02827e
Henrik, want to test a tryserver build (once such is ready)?
(hopefully the builds don't crash immediately :) )
Assignee | ||
Updated•4 years ago
|
Reporter | ||
Comment 11•4 years ago
|
||
Sure. I could do once the code compiles. Can you fix the timerid
problem and push again? Should I use an opt or debug build then?
Assignee | ||
Comment 12•4 years ago
|
||
oh, lovely, it compiled locally. Pushing again.
Assignee | ||
Comment 13•4 years ago
|
||
Assignee | ||
Updated•4 years ago
|
Reporter | ||
Comment 14•4 years ago
|
||
I tried this build but I cannot get anything to play beside the advertisement as shown first for every content. Maybe the changes broke some behavior?
Mind trying yourself at https://www.tvnow.de/serien/unter-uns-20/2020-05? Just click the play button and wait until the advertisement is done. You should see a black screen then.
Beside that I also face problems with other media content on this side which cannot be played due to broken/missing DRM. Maybe something is not correctly enabled in a try build and we would have to generate a Nightly build?
Assignee | ||
Comment 15•4 years ago
•
|
||
I get DRM error.
...ah I can get passed that by accepting installing drm components on Nightly
Reporter | ||
Comment 16•4 years ago
|
||
Hey Bryce, can you help us here to get around the DRM error? Please see my comment 14 for details. Thanks!
(In reply to Henrik Skupin (:whimboo) [⌚️UTC+2] from comment #16)
Hey Bryce, can you help us here to get around the DRM error? Please see my comment 14 for details. Thanks!
Looking at the edit in comment 15 it sounds like this may be a matter of toggling DRM on in Options -> General. Let me know if I'm mistaken and I can look further.
Reporter | ||
Comment 18•4 years ago
|
||
That preference is turned on for me. It's the reason why it is puzzling.
Debugged out of band. Please reach out again as needed.
Reporter | ||
Comment 20•4 years ago
•
|
||
I tested the try build for a couple of hours, and also after putting MacOS in sleep mode during the night. It all looks fine and the improvements are outstanding. There is no longer a Firefox parent process around that keeps a core busy at 100%. So not only a performance improvement, but also counts a lot to power usage reduction. Thanks a lot Olli!
Comment 21•4 years ago
|
||
Pushed by opettay@mozilla.com: https://hg.mozilla.org/integration/autoland/rev/1c58f39177c0 clearing timeouts should be O(1) r=farre
Comment 22•4 years ago
|
||
Bustages at TimeoutManager.cpp.
https://hg.mozilla.org/integration/autoland/rev/53445bcdff8e06da6f89621915599872736c029f
Push with failures: https://treeherder.mozilla.org/#/jobs?repo=autoland&revision=1c58f39177c0ea2e3bbd22fbb92fab39f8c9d2e0&selectedTaskRun=K1cv1W9QTQawklV2Hw47DQ-0
Failure log: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=303213113&repo=autoland&lineNumber=25998
Assignee | ||
Comment 24•4 years ago
|
||
Comment 25•4 years ago
|
||
Pushed by opettay@mozilla.com: https://hg.mozilla.org/integration/autoland/rev/30fedc6e38f8 clearing timeouts should be O(1),
Reporter | ||
Comment 26•4 years ago
|
||
(In reply to Olli Pettay [:smaug] from comment #23)
Why I can't reland with the trivial fix...
Because it is still marked as closed. With a backout it needs to be reopened, and I assume that's automatically done by the sheriffs or a script? Not sure why that didn't happen here.
Comment 27•4 years ago
|
||
On Thursday, a sheriff had to oops hg backout
instead of hg oops
which puts the bug number before the revision hash and this doesn't get picked up by the Phabricator script which reopens revisions. Sorry about that.
Comment 28•4 years ago
|
||
bugherder |
Reporter | ||
Comment 29•4 years ago
|
||
After two days using this site excessively I can verify that the CPU load is all normal now. No more process running at 100% in the background and the battery holds way longer. Now I cannot await to see it in beta soon. Thanks again Olli!
Reporter | ||
Updated•3 years ago
|
Description
•