854803 - Images on slow network continously use 1 full core.

Status: VERIFIED FIXED

(Core :: Graphics: ImageLib, defect)

Description

[Mayank Bansal]

User Agent: Mozilla/5.0 (Windows NT 6.1; WOW64; rv:22.0) Gecko/20130325 Firefox/22.0
Build ID: 20130325105600

Steps to reproduce:

1. Create fresh profile.
2. Go to http://images.anandtech.com/doci/6857/7970_BLACK_PCB_678x452.png
3. Monitor task manager.


Actual results:

FF continously uses 1 complete core. The image is small in size, ~200KB.


Expected results:

Not so.

Comment 1

[Mayank Bansal]

Something like if an image is on a very slow network, it is being continously processed or something.
This ~200KB took 22 seconds to load, using 1 full core the whole time.

Profile : http://people.mozilla.com/~bgirard/cleopatra/#report=e30419955389892340f66c0f5ba8c4441769d221



This also occured to me on 9gag, when i was using a 8KB/s internet connection.

Comment 2

[Willy_ Foo_Foo]

Me too facing the same problem on medium connection
or pages with loads of thumbnails

Comment 3

[Willy_ Foo_Foo]

add this as a blocker to 854394

Comment 4

[Willy_ Foo_Foo]

Visit Fb.com
see cpu usage Goto 75%-100%
no matter how much decoding/rendering is done
Cpu/Gpu usage should be minimal(plus save heating & battery)

Comment 5

[Mayank Bansal]

(In reply to Sillius Soddus from comment #4)
> Visit Fb.com
> see cpu usage Goto 75%-100%
> no matter how much decoding/rendering is done
> Cpu/Gpu usage should be minimal(plus save heating & battery)


Please stop spamming this bug.
If you believe there is a problem in Firefox, file a *new* bug.

Comment 6

[(mostly gone) XtC4UaLL [:xtc4uall]]

Does playing with the image.multithreaded_decoding.limit Pref (e.g. set to 1) make any Difference?

Comment 7

[Mayank Bansal]

cant check now :(
The load on the network has reduced, so the image streams in a second.

Can anyone host this image on a speed-limited server, and try to repro ?

Comment 8

[Mayank Bansal]

OK, i reproduced this by installing netbalancer from here : http://seriousbit.com/netbalancer/ 

I limit the upload and download limit of Nightly to 6KB/s.

Then i go to the  URL ( you may have to ctrl+F5 to bypass the disk cache)

Result : 

Nightly  -- >  100% CPU usage while the image loads (1 core)
Release 19  -->  2-3% load.

100% load reproducible with  image.multithreaded_decoding.limit set to both the default value (-1) and (1) as suggested in comment 6.

Comment 9

[Robert Lickenbrock [:rclick]]

(In reply to Sillius Soddus from comment #3)
> add this as a blocker to 854394

Bug 854394 is about tuning when we do synchronous decoding on the main thread, which is unrelated to this bug.

Comment 10

[Mayank Bansal]

This is happening to me a lot, because i have a poor ISP who reduce speed or make some sites slow to load.
Issue manifests as 100% load on one core, resulting in laptop heating up and fan whirring.

(This does not affect the snappy-ness of the browser in any way though.)

Comment 11

[Yuan Pengfei]

(In reply to mayankleoboy1 from comment #10)
> This is happening to me a lot, because i have a poor ISP who reduce speed or
> make some sites slow to load.
> Issue manifests as 100% load on one core, resulting in laptop heating up and
> fan whirring.
> 
> (This does not affect the snappy-ness of the browser in any way though.)

You may temporarily disable image.multithreaded_decoding.enabled

Comment 12

[Alice0775 White]

Confirmed on restricted network 9kbps VMware Player.

Comment 13

[Alice0775 White]

Regression window(m-c)
Good:
http://hg.mozilla.org/mozilla-central/rev/bef19bca23f9
Mozilla/5.0 (Windows NT 5.1; rv:22.0) Gecko/20130325 Firefox/22.0 ID:20130325015122
Bad:
http://hg.mozilla.org/mozilla-central/rev/4d3250f3afea
Mozilla/5.0 (Windows NT 5.1; rv:22.0) Gecko/20130325 Firefox/22.0 ID:20130325093524
Pushlog:
http://hg.mozilla.org/mozilla-central/pushloghtml?fromchange=bef19bca23f9&tochange=4d3250f3afea


Regression window(m-i)
Good:
http://hg.mozilla.org/integration/mozilla-inbound/rev/71fe5b69c834
Mozilla/5.0 (Windows NT 5.1; rv:22.0) Gecko/20130324 Firefox/22.0 ID:20130324205822
Bad:
http://hg.mozilla.org/integration/mozilla-inbound/rev/1541b7a03e17
Mozilla/5.0 (Windows NT 5.1; rv:22.0) Gecko/20130324 Firefox/22.0 ID:20130324220925
Pushlog:
http://hg.mozilla.org/integration/mozilla-inbound/pushloghtml?fromchange=71fe5b69c834&tochange=1541b7a03e17

In local build:
Last Good: 71fe5b69c834
First Bad: 9e2bdda8c3ca
Triggered by:
  9e2bdda8c3ca Joe Drew — Bug 716140 - Implement multithreaded decoding using a thread pool. r=seth


Strangely, image.multithreaded_decoding.enabled=false does not help.

Comment 14

[Robert Lickenbrock [:rclick]]

I can reproduce using netbalancer to simulate a slow network. I'm looking into it.

Comment 15

[Robert Lickenbrock [:rclick]]

Attachment: Part 1: Account for more decoder state in RasterImage::IsDecodeFinished()

IsDecodeFinished can sometimes be wrong because it checks the RasterImage's size and decode done state, which might not have been synchronized yet. The solution is to check the decoder's equivalent state.

Additionally, I added a check for the case where we've allocated a new frame but haven't yet flushed the data the decoder set aside. We do check for this elsewhere, but not consistently. Checking for it in IsDecodeComplete makes it so.

Comment 16

[Robert Lickenbrock [:rclick]]

Attachment: Part 2: Don't try to enqueue more decoding from DecodeDoneWorker

The problem here is that DecodeDoneWorker always requests more decoding, even if we've decoded all the data we have and we're waiting on the network to send more. What ends up happening is DecodeDoneWorker enqueues a DecodeJob, and that dispatches another DecodeDoneWorker... We constantly do this in a loop until we receive enough data to finish the decode.

The solution I've opted for is to simply not trigger more decoding. DecodeDoneWorker only gets dispatched after we've done all the decoding we can, so it shouldn't be necessary.

Comment 17

[Seth Fowler [:seth] [:s2h]]

Comment on attachment 731774 [details] [diff] [review]
Part 1: Account for more decoder state in RasterImage::IsDecodeFinished()

Review of attachment 731774 [details] [diff] [review]:
-----------------------------------------------------------------

Looks great!

::: image/src/RasterImage.cpp
@@ +3343,5 @@
>  RasterImage::IsDecodeFinished()
>  {
>    // Precondition
>    NS_ABORT_IF_FALSE(mDecoder, "Can't call IsDecodeFinished() without decoder!");
> +  MOZ_ASSERT(mDecodeRequest);

I think we should add mDecodingMutex.AssertCurrentThreadOwns() here. If we don't hold the lock then a lot of this stuff is unsafe. (We always do hold the lock right in IsDecodedFinished right now, but it'd be good to catch this if something changes in the code later.)

Comment 18

[Seth Fowler [:seth] [:s2h]]

Comment on attachment 731783 [details] [diff] [review]
Part 2: Don't try to enqueue more decoding from DecodeDoneWorker

Review of attachment 731783 [details] [diff] [review]:
-----------------------------------------------------------------

I concur, this should be fine. AddSourceData should take care of calling RequestDecode in the situations where it's necessary as soon as new data arrives.

Comment 19

[Robert Lickenbrock [:rclick]]

Thanks for the review!

(In reply to Seth Fowler [:seth] from comment #17)
> I think we should add mDecodingMutex.AssertCurrentThreadOwns() here. If we
> don't hold the lock then a lot of this stuff is unsafe. (We always do hold
> the lock right in IsDecodedFinished right now, but it'd be good to catch
> this if something changes in the code later.)

I completely agree. Will do.

Comment 20

[Robert Lickenbrock [:rclick]]

This had a mostly green try run (https://tbpl.mozilla.org/?tree=Try&rev=8360f6cd74a9). I suspect the failures aren't caused by my patches, though I will look closer to make sure.

Builds are available at http://ftp.mozilla.org/pub/mozilla.org/firefox/try-builds/[e-mail]-8360f6cd74a9 if anyone wants to test them.

Comment 22

[Seth Fowler [:seth] [:s2h]]

The try run looks good to me. I'd love to get this landed ASAP.

Comment 23

[Robert Lickenbrock [:rclick]]

Attachment: Part 1: Account for more decoder state in RasterImage::IsDecodeFinished()

Addressed review comments and added r=seth to commit message.

Comment 24

[Robert Lickenbrock [:rclick]]

Attachment: Part 2: Don't try to enqueue more decoding from DecodeDoneWorker

Added r=seth to commit message.

Comment 25

[Robert Lickenbrock [:rclick]]

Requesting check-in.

The assertion added in part 1 shouldn't need another try run because there's no way it could possibly fail without other already existing assertions also failing.

Comment 26

[Robert Lickenbrock [:rclick]]

It would help if I remembered to actually qref the patch...

Comment 27

[Robert Lickenbrock [:rclick]]

Attachment: Part 1: Account for more decoder state in RasterImage::IsDecodeFinished()

The right patch this time. Sorry for the bugspam.

Comment 28

[Robert Lickenbrock [:rclick]]

Attachment: Part 2: Don't try to enqueue more decoding from DecodeDoneWorker

Comment 29

[Seth Fowler [:seth] [:s2h]]

Great! Pushed to inbound:

https://hg.mozilla.org/integration/mozilla-inbound/rev/2dc2f5db57ea
https://hg.mozilla.org/integration/mozilla-inbound/rev/29f935fba166

Comment 30

[Ryan VanderMeulen [:RyanVM]]

https://hg.mozilla.org/mozilla-central/rev/2dc2f5db57ea
https://hg.mozilla.org/mozilla-central/rev/29f935fba166

Comment 31

[Willy_ Foo_Foo]

(In reply to Robert Lickenbrock [:rclick] from comment #28)
> Created attachment 733099 [details] [diff] [review]
> Part 2: Don't try to enqueue more decoding from DecodeDoneWorker

(In reply to Seth Fowler [:seth] from comment #29)
> Great! Pushed to inbound:
> 
> https://hg.mozilla.org/integration/mozilla-inbound/rev/2dc2f5db57ea
> https://hg.mozilla.org/integration/mozilla-inbound/rev/29f935fba166

(In reply to Ryan VanderMeulen [:RyanVM] from comment #30)
> https://hg.mozilla.org/mozilla-central/rev/2dc2f5db57ea
> https://hg.mozilla.org/mozilla-central/rev/29f935fba166

*new profile*
Still seeing very high Cpu usage on Site with Images
Continuous 40% to 60% CPU usage
also on a side not
It feels as if the images reload from the server every time FF23 is started after browsing some sites closing FF,again visiting same sites?
(bypassing cache thought about:cache shows caches being saved)
beta version seems Fine

Comment 32

[Willy_ Foo_Foo]

Attachment: Still High CPU usage/two screenshots/on new profile

Still High CPU usage with sites with images//two screenshots//New Profile

Comment 33

[Willy_ Foo_Foo]

Attachment: On windows/Linux with a fresh profile HWA disabled

Comment 34

[Seth Fowler [:seth] [:s2h]]

(In reply to ElevenReds from comment #32)
> Created attachment 734147 [details]
> Still High CPU usage/two screenshots/on new profile
> 
> Still High CPU usage with sites with images//two screenshots//New Profile

Please file a new bug with specific steps to reproduce the issue. I'd prefer if you would wait 24 hours, though, and then ensure that you can still reproduce the issue with the next Nightly release. A lot of bugs related to image decoding have been fixed within the past day or so.

FWIW, I cannot reproduce any of the problems listed on this bug anymore.

Comment 35

[Willy_ Foo_Foo]

(In reply to Seth Fowler [:seth] from comment #34)
> (In reply to ElevenReds from comment #32)
> > Created attachment 734147 [details]
> > Still High CPU usage/two screenshots/on new profile
> > 
> > Still High CPU usage with sites with images//two screenshots//New Profile
> 
> Please file a new bug with specific steps to reproduce the issue. I'd prefer
> if you would wait 24 hours, though, and then ensure that you can still
> reproduce the issue with the next Nightly release. A lot of bugs related to
> image decoding have been fixed within the past day or so.
> 
> FWIW, I cannot reproduce any of the problems listed on this bug anymore.


Compared to FF21beta isnt the CPU usage far more(attachment)

Sure will wait :)

Thanks

Comment 36

[Jan Alexander Steffens [:heftig]]

Can the fixes for this problem be uplifted to aurora, please?

Comment 37

[Seth Fowler [:seth] [:s2h]]

Whoa there. Bug 859718 is a regression caused by this bug. (Which I'm about to upload a patch for.) This should _not_ be uplifted without that fix being included.

Comment 38

[Seth Fowler [:seth] [:s2h]]

Bug 859718 has hit m-c as of yesterday. If I don't hear of any regressions by tonight I'm going to nominate both this bug and bug 859718 for uplift to Aurora.

Comment 39

[Robert Lickenbrock [:rclick]]

I don't have anything to add beyond what Seth has already said. Uplifting is blocked on Bug 859718.

Comment 40

[Seth Fowler [:seth] [:s2h]]

Comment on attachment 733098 [details] [diff] [review]
Part 1: Account for more decoder state in RasterImage::IsDecodeFinished()

[Approval Request Comment]
Bug caused by (feature/regressing bug #): 716140
User impact if declined: Continuous high CPU usage in some situations.
Testing completed (on m-c, etc.): On m-c since 2013-04-04. One regression identified and fixed in bug 859718, which is also approval-mozilla-aurora? and should be uplifted with this patch.
Risk to taking this patch (and alternatives if risky): Low risk. This modifies how image decoders behave, but the changes are not complex and have been tested for two weeks now.
String or IDL/UUID changes made by this patch: None.

Comment 41

[Seth Fowler [:seth] [:s2h]]

Comment on attachment 733099 [details] [diff] [review]
Part 2: Don't try to enqueue more decoding from DecodeDoneWorker

[Approval Request Comment]
(Same as above.)

Comment 42

[bhavana bajaj [:bajaj]]

Comment on attachment 733098 [details] [diff] [review]
Part 1: Account for more decoder state in RasterImage::IsDecodeFinished()

Please make sure to uplift patch in Bug 859718 when uplifting this.Thank you !

Comment 43

[bhavana bajaj [:bajaj]]

Comment on attachment 733099 [details] [diff] [review]
Part 2: Don't try to enqueue more decoding from DecodeDoneWorker

Well tested on nightly, regression from Bug 716140 - Multithreaded image decoding which is in Fx 22. Avoids use of high CPU utilization which was reported to happen in a few scenario's .

Comment 44

[Ryan VanderMeulen [:RyanVM]]

https://hg.mozilla.org/releases/mozilla-aurora/rev/d8135447bfec
https://hg.mozilla.org/releases/mozilla-aurora/rev/50055800e40c

Comment 45

[Mihai Morar, (:MihaiMorar)]

I confirm the fix is verified on FF 22.b1 on windows 7 x64:

Mozilla/5.0 (Windows NT 6.1; WOW64; rv:22.0) Gecko/20100101 Firefox/22.0(20130514181517)

Comment 46

[Mihai Morar, (:MihaiMorar)]

I confirm the fix is verified on FF 23b4 too on windows 7 x64:

Mozilla/5.0 (Windows NT 6.1; WOW64; rv:23.0) Gecko/20100101 Firefox/23.0(20130708202947)