487638 - status bar blames wrong resource when downloading slow responding resource

Status: RESOLVED FIXED

(Core :: Networking, defect)

Description

[bnkuhn]

User-Agent:       Mozilla/5.0 (Macintosh; U; Intel Mac OS X 10.5; en-US; rv:1.9.2a1pre) Gecko/20090409 Minefield/3.6a1pre
Build Identifier: Mozilla/5.0 (Macintosh; U; Intel Mac OS X 10.5; en-US; rv:1.9.2a1pre) Gecko/20090409 Minefield/3.6a1pre

If an image or script is requested from a server that is slow to respond, the status bar in Firefox says that it is still downloading the previous resource, which has actually finished downloading.  This leads to users blaming the previous resource for slow loading pages.

I believe this happens because Firefox doesn't update the status bar until it starts receiving data from the slow server.  It should however update the status bar as soon at it makes the request for a new resource.

I've created example pages here:
http://analytics.nfshost.com/case3.html  (slow image)
http://analytics.nfshost.com/case3b.html (slow script)

Reproducible: Always

Steps to Reproduce:
1. Find URLs for two scripts; one that loads quickly and one that takes a long time for the server to start sending back data.
2. Insert both scripts into a page (the quick one right before the slow one).
3. Open the page in Firefox and notice that the status bar says it's waiting on the first script for a long time; it will only start blaming the second script once its server starts sending back data.
Actual Results:  
Status bar blames the previous resource until the current resource's server starts sending back data.

Expected Results:  
Status bar should blame the current resources as soon as it makes the request for it.

I'm able to reproduce this with Firefox 3 on Windows, Linux and Mac every time.  I've only tested the nightly build on Mac.

By "blame", I mean the status bar says something like, "waiting on www.google-analytics.com..." when it's actually waiting on another resource.

I'm a member of the Google Analytics team, and this is a major issue for us.  We often get blamed for slowing down pages (in Firefox) that are actually being slowed down by other resources.

Comment 1

[Tyler Downer [He/Him]]

You have only tried trunk on Mac? Does Safe Mode or a new profile make a difference? (Probably won't, but good to make sure).

Comment 2

[bnkuhn]

I have now repeated this on Mac, XP and Linux with trunk/safe mode/new profile.

Comment 4

[bmccann]

I had opened a bug for this as well, which I've now closed as being a duplicate of this bug.  Here's another example page: http://www.benmccann.com/test/firefox-status-bar-lies.html

Comment 5

[bnkuhn]

I'm going to poke around the source a bit to see how difficult of a fix this might be.  If anyone has any advice on where to find the pertinent code, please let me know.

Comment 6

[Christian :Biesinger (don't email me, ping me on IRC)]

Ah right. I was going to look at it too, but if you want to, go ahead.

The code flow is basically this:
nsHttpChannel::OnTransportStatus calls mProgressSink->OnStatus
that's:
nsDocLoader::OnStatus - this function creates the "Transferring data from ..." string
it calls:
nsBrowserStatusFilter::OnStatusChange (this class is a mess, btw)
which calls, sooner or later,
XULBrowserWindow.onStatusChange in browser.js

The problem is, I guess, that after the google-analytics file finishes loading, there are no new status events, so the status bar doesn't change.

Comment 7

[bnkuhn]

Thanks for the info.  I'm only looking into it because I couldn't find someone to work on that was already experienced hacking Firefox.  I have zero experience with the code base, so this should be interesting ;)

Comment 8

[Christian :Biesinger (don't email me, ping me on IRC)]

Attachment: Patch

This patch does the following:
- Makes nsDocLoader store the last-sent status message for each request in the corresponding nsRequestInfo, and keeps a flag to indicate whether the request is done
- When a request finishes, it looks for a random request that is not done and has a non-empty status, and if it finds one, sends that status message to the listeners
- To make this all work, the patch also changes imagelib so that status and state messages sent for images are sent with the imgIRequest as the request and not the channel. This is necessary because the channel is not part of the loadgroup for images, only the imgIRequest is.

Comment 9

[Boris Zbarsky [:bzbarsky]]

Comment on attachment 388650 [details] [diff] [review]
Patch

How often do the notifications come in?  Would it make sense to cache the progress event sink for the channel?  Or do we never know when it might change?

Returning PR_FALSE in imgLoader::LoadImage is certainly wrong.  I suggest NS_ERROR_OUT_OF_MEMORY instead.

I'd prefer a method on nsRequestInfo that returns the nsIRequest*.

I assume when all requests finish we'll change the status from somewhere else, so don't have to worry about those cases?

r+sr=bzbarsky, with the nits picked (esp. the incorrect return value).

Comment 10

[Christian :Biesinger (don't email me, ping me on IRC)]

(In reply to comment #9)
> (From update of attachment 388650 [details] [diff] [review])
> How often do the notifications come in?  Would it make sense to cache the
> progress event sink for the channel?  Or do we never know when it might change?

Yeah, it can change at any time, especially when extensions are involved...

> Returning PR_FALSE in imgLoader::LoadImage is certainly wrong.  I suggest
> NS_ERROR_OUT_OF_MEMORY instead.

Oops. Thanks.

> I'd prefer a method on nsRequestInfo that returns the nsIRequest*.

Done.

> I assume when all requests finish we'll change the status from somewhere else,
> so don't have to worry about those cases?

That's the responsibility of the callee, in case of Firefox browser.js, which displays the Done message. It gets an onStateChange message for that purpose.

Comment 11

[Christian :Biesinger (don't email me, ping me on IRC)]

Attachment: patch v2

Comment 12

[Christian :Biesinger (don't email me, ping me on IRC)]

Attachment: patch v2, merged to trunk

Comment 13

[Christian :Biesinger (don't email me, ping me on IRC)]

Attachment: additional patch to nsBrowserStatusFilter

This patch is needed for an edge case... (I hit that sometimes when clicking reload on the testcase here)

Basically, when nsBrowserStatusFilter has a pending status change, it needs to compare the new status to the pending status instead of the current status, because otherwise the (now incorrect) pending status will be sent to the UI.

Comment 14

[Boris Zbarsky [:bzbarsky]]

One other note.  The imagelib behavior will still be screwy if the imgRequestProxy is canceled before the underlying channel is done loading but while it has other proxies.  We'll keep delivering the channel's status notifications with that canceled proxy as the request.  Is that ok?

Comment 15

[Boris Zbarsky [:bzbarsky]]

Comment on attachment 391062 [details] [diff] [review]
additional patch to nsBrowserStatusFilter

mCurrentStatusMsg is write-only after this, no?  Please remove it?

Comment 16

[Christian :Biesinger (don't email me, ping me on IRC)]

Attachment: complete patch

This is the two previous patches as a single file. For nsBrowserStatusFilter, I did it this way instead which seems better (avoids calls to onStatusChange when not needed):
-    if (!mCurrentStatusMsg.Equals(aMessage)) {
+    if (mStatusIsDirty || !mCurrentStatusMsg.Equals(aMessage)) {

I think the image behaviour isn't terrible even when the imgIRequest gets cancelled... I think it's good to still have the status bar updates when the image is still loading elsewhere on that page. But I could also change the code to check the request's status before forwarding onStatus/onProgress, if you want me to.

Comment 17

[Christian :Biesinger (don't email me, ping me on IRC)]

Fixed for 1.9.2a1!

http://hg.mozilla.org/mozilla-central/rev/dcda49ff1a26

Comment 18

[Christian :Biesinger (don't email me, ping me on IRC)]

Attachment: fix memory leaks

need to call the destructor of nsRequestInfo

Comment 19

[Boris Zbarsky [:bzbarsky]]

Comment on attachment 391120 [details] [diff] [review]
fix memory leaks

Put the opening curly on its own line, and looks good.

Comment 20

[Christian :Biesinger (don't email me, ping me on IRC)]

http://hg.mozilla.org/mozilla-central/rev/7149d895e5b3