1329630 - Firefox constantly uses 100% CPU after long time movie browsing, even after closing movies

Status: VERIFIED FIXED

(Core :: Audio/Video: Playback, defect, P1)

Description

[Virtual_ManPL [:Virtual] 🇵🇱 - (please needinfo? me - so I will see your comment/reply/question/etc.)]

STR:
1. Do the long time browsing session with many movies in HTML5 media format on YouTube or other streaming website.
2. After some time, like 15-30min typically, you will enjoy that Firefox constantly uses 100% of your CPU, even after closing all tabs and windows with staying with the white blank one.


[Tracking Requested - why for this release]: Regression

Comment 1

[Virtual_ManPL [:Virtual] 🇵🇱 - (please needinfo? me - so I will see your comment/reply/question/etc.)]

Attachment: Profile taken with Gecko Profiler (LZMA2).7z

Comment 2

[Virtual_ManPL [:Virtual] 🇵🇱 - (please needinfo? me - so I will see your comment/reply/question/etc.)]

Just to add, that it's still happens with disabled: e10s, GPU Process (content) and GPU Process (media).

Comment 3

[Randell Jesup [:jesup] (needinfo me)]

Anything useful in the profile?

Comment 4

[Marcia Knous [:marcia]]

Tracking 53+ so we can get to the bottom of what might be going on here.

Comment 5

[Marcia Knous [:marcia]]

Tracking for 54 as well.

Comment 6

[Vlad Bacia-Mociran [:VladB]]

User Agent: Mozilla/5.0 (Windows NT 6.1; Win64; x64; rv:54.0) Gecko/20100101 Firefox/54.0
User Agent: Mozilla/5.0 (Windows NT 6.3; Win64; x64; rv:54.0) Gecko/20100101 Firefox/54.0

I have tested your issue on latest Nightly (Build ID: 20170215030342) and could not reproduce it. I have opened about 10-15 videos from YouTube. The length of the videos varied from 1h to 3h. They were playing simultaneous in Nightly for about 30m-1h with e10s ON and OFF but the CPU usage was never above 50%. After all tabs with videos were closed, only about:home page was displayed, the CPU and memory usage returned to normal.

The two systems on which the tests were performed have:
- CPU: AMD FX(tm)-8320 Eight-Core Processor 3,5GHz ; GPU: GeForce 210 ; RAM: 16GB
- CPU: Intel i5-3470 3,2GHz ; GPU Radeon R7 360 series ; RAM: 8GB

@Virtual_ManPL, on what system did you encounter this issue? Was e10s ON or OFF? Can you provide more information about the system that you used?

Is this still reproducible on your end ? If yes, can you please retest this using latest Nightly build (https://nightly.mozilla.org/) and report back the results ? When doing this, please use a new clean Firefox profile, maybe even safe mode, to eliminate custom settings as a possible cause (https://goo.gl/AR5o9d).

Comment 7

[Virtual_ManPL [:Virtual] 🇵🇱 - (please needinfo? me - so I will see your comment/reply/question/etc.)]

(In reply to Vlad Bacia-Mociran [:VladB] from comment #6)
> @Virtual_ManPL, on what system did you encounter this issue?
> Was e10s ON or OFF?
> Can you provide more information about the system that you used?
It's in "Platform:" and Comment #2,
but I'm working on Windows 7 (64bit) with Mozilla Firefox Nightly (64bit) with enabled e10s.
Disabling e10s, GPU Process (content) and GPU Process (media) didn't have any effect.

(In reply to Vlad Bacia-Mociran [:VladB] from comment #6)
> Is this still reproducible on your end ?
Yes.

(In reply to Vlad Bacia-Mociran [:VladB] from comment #6)
> If yes, can you please retest this using
> latest Nightly build (https://nightly.mozilla.org/)
> and report back the results ?
It's reproducible in latest Mozilla Firefox Nightly 54.0a1 (2017-02-15) (64-bit).

(In reply to Vlad Bacia-Mociran [:VladB] from comment #6)
> When doing this, please use a new clean Firefox profile,
It's reproducible with clean new fresh profile without any addons (extensions and plugins).

(In reply to Vlad Bacia-Mociran [:VladB] from comment #6)
> maybe even safe mode, to eliminate custom settings
> as a possible cause (https://goo.gl/AR5o9d).
It's reproducible in Safe Mode.



I also attached profile in which something could be useful and maybe will gave us some hint to find to culprit.

Moreover looks like I'm not the only one with this problem - http://forums.mozillazine.org/viewtopic.php?p=14733149#p14733149

Comment 8

[Virtual_ManPL [:Virtual] 🇵🇱 - (please needinfo? me - so I will see your comment/reply/question/etc.)]

Attachment: Firefox 2017-02-21 18.14 profile.sps.json.gz

I redone my test and profile is here - https://perfht.ml/2miAGVr + attached in Comment 8

Taken with Gecko Profiler 2.0.31 with these settings:
- Interval = 0,01ms
- Buffer size = 900MB
- Threads = GeckoMain,Compositor
- Features = Stack walk, JavaScript, Task tracer

Comment 9

[Jean-Yves Avenard [:jya]]

can you re-run a profiler with e10s disabled?

Comment 10

[Virtual_ManPL [:Virtual] 🇵🇱 - (please needinfo? me - so I will see your comment/reply/question/etc.)]

Attachment: Firefox 2017-02-26 00.51 profile.sps.json.gz

(In reply to Jean-Yves Avenard [:jya] from comment #9)
> can you re-run a profiler with e10s disabled?

Sure. Have a look, profile is here - https://perfht.ml/2lbOT5A + attached in comment #10

Comment 11

[Virtual_ManPL [:Virtual] 🇵🇱 - (please needinfo? me - so I will see your comment/reply/question/etc.)]

Attachment: Firefox 2017-03-01 12.43 profile.sps.json.gz

I done again my test with e10s enabled, when issue appeared I closed all tabs and windows, so only New Tab remain and started catching profile without doing anything for over 1min.
Profile is here - https://perfht.ml/2lSHYSG + attached in Comment 11

Taken with Gecko Profiler 2.0.31 with these settings:
- Interval = 0,01ms
- Buffer size = 900MB
- Threads = GeckoMain,Compositor
- Features = Stack walk, JavaScript, Task tracer

Comment 12

[Randell Jesup [:jesup] (needinfo me)]

I'm afraid all that tells us is that the thread using the CPU isn't Main or Compositor, which isn't surprising.

Perhaps with Threads= (empty); I *think* that will capture all nsThreads.  If I had a build in a debugger, I'd just hit break and see what thread it was in.

Comment 13

[Randell Jesup [:jesup] (needinfo me)]

Generating a crashdump/crashreport with https://addons.mozilla.org/en-US/firefox/addon/crash-me-now-simple/ might tell us what thread if ilooping.  (I suggest getting several crashes this way so we can correlate what threads appear active)

Comment 14

[Virtual_ManPL [:Virtual] 🇵🇱 - (please needinfo? me - so I will see your comment/reply/question/etc.)]

Should I get these profiles and crashes now with e10s enabled or disabled, or it just doesn't matter?

Comment 15

[Randell Jesup [:jesup] (needinfo me)]

e10s - from your discussion above, doesn't matter.  I'd suggest verifying you're successfully capturing a lot more threads before working to repro in a profile.

Comment 16

[Jean-Yves Avenard [:jya]]

Could it be the same as bug 1344357?

Comment 17

[Jean-Yves Avenard [:jya]]

Alice0075; are you able to reproduce the problem?
Seeing you're the champion of regression finding? Could you identify this one?
Thank you

Comment 18

[Alice0775 White]

(In reply to Jean-Yves Avenard [:jya] from comment #17)
> Alice0075; are you able to reproduce the problem?
> Seeing you're the champion of regression finding? Could you identify this
> one?
> Thank you


I watched youtube play list ( https://www.youtube.com/watch?v=ydKcKJIq6AI&list=PUxVlUVEiwY43qLhCB7kMBIw , contains 200 videos) for 1hr.
However, 
I could not reproduce the problem on Nightly54.0a1 32bit on Windows10 64bit and Windows7 64bit VM.
After closing the youtube tab, the CPU utilization drops normally.

Comment 19

[Randell Jesup [:jesup] (needinfo me)]

Any other ideas on how to move forward?  I suspect we need someone to repro it (or show it no longer repros).

Comment 20

[Jean-Yves Avenard [:jya]]

i can't reproduce it myself...

Comment 21

[Virtual_ManPL [:Virtual] 🇵🇱 - (please needinfo? me - so I will see your comment/reply/question/etc.)]

(In reply to Randell Jesup [:jesup] from comment #15)
> e10s - from your discussion above, doesn't matter.  I'd suggest verifying
> you're successfully capturing a lot more threads before working to repro in
> a profile.

Unfortunately for me this will be impossible due to the same issue mentioned by me in bug #1300235 comment #37, which is the bug #1344576. I will try some other things mentioned bug #1300235 comment #39 to omit this.

Comment 22

[Virtual_ManPL [:Virtual] 🇵🇱 - (please needinfo? me - so I will see your comment/reply/question/etc.)]

Attachment: Firefox 2017-03-12 19.07 profile.sps.json.gz

I finally caught the working no crashy profile - https://perfht.ml/2nj6wTj + attached in Comment 22

Taken with Gecko Profiler 2.0.34 with these settings:
- Interval = 100ms
- Buffer size = 90MB
- Threads = ,
- Features = Stack walk

Comment 23

[Randell Jesup [:jesup] (needinfo me)]

The only threads I see that aren't 100% waiting appear to be MediaPlayback threads.  waiting on semaphores some, etc, generally called from TaskQueue::Runner::Run() -> Dispatch() -> nsSharedThreadPool::Dispatch

Comment 24

[Blake Wu [:bwu][:blakewu]]

JW,
Can you help check this bug? 
This is marked as 53 regression bug. We need to check it in priority. 
Thanks.

Comment 25

[JW Wang [:jwwang] [:jw_wang]]

(In reply to Virtual_ManPL [:Virtual] - (please needinfo? me) from comment #22)
> Created attachment 8846427 [details]
> Firefox 2017-03-12 19.07 profile.sps.json.gz
> 
> I finally caught the working no crashy profile - https://perfht.ml/2nj6wTj +
> attached in Comment 22
> 
> Taken with Gecko Profiler 2.0.34 with these settings:
> - Interval = 100ms
> - Buffer size = 90MB
> - Threads = ,
> - Features = Stack walk

I have the same conclusion as Randell. TaskQueue::Runner::Run() takes no more than 20% of the CPU time and shouldn't be the bottleneck.

I also see MediaFormatReader::NotifyDataArrived() in MediaPlayback #1 and we happen to have a bug about that which is bug 1344772.

Can you try Nightly again to see if bug 1344772 happens to fix this issue?

Comment 26

[Virtual_ManPL [:Virtual] 🇵🇱 - (please needinfo? me - so I will see your comment/reply/question/etc.)]

(In reply to JW Wang [:jwwang] [:jw_wang] from comment #25)
> Can you try Nightly again to see if bug 1344772 happens to fix this issue?

Sure. I will report back after week of testing, to test it deeply, as it's extremely time consuming to reproduce.

Comment 27

[Virtual_ManPL [:Virtual] 🇵🇱 - (please needinfo? me - so I will see your comment/reply/question/etc.)]

After testing Mozilla Firefox Nightly for few days, I'm pretty sure that patches from bug #1344772 also fixed issues in this bug.

Comment 28

[Jean-Yves Avenard [:jya]]

great to know.. thank you for reporting...

Comment 29

[Virtual_ManPL [:Virtual] 🇵🇱 - (please needinfo? me - so I will see your comment/reply/question/etc.)]

Per bug #1344772 comment #17, I'm marking this bug as unaffected on Firefox 53, as patch from bug #1319992, which was causing this issue was backed out from Firefox 53 in bug #1326372.