435432 - Content Encoding error when "Visit Home Page" from add-ons window

Status: RESOLVED INVALID

(Core :: Networking: HTTP, defect)

Description

[Kathleen :Brade]

Attachment: Wireshark tcp stream trace

I'm seeing a problem in Firefox 3 (Mac and Windows) that I don't see in Firefox 2.  If I choose "Visit Home Page" from the add-ons window, I get a "Content Encoding Error"; if I clear the cache and load the page from the location bar, the page loads fine.

It seems strange to me that the page will load fine within the browser but not from the Add-ons window.

Steps to reproduce:
1) Install Keyword Box add-on (from add-ons.mozilla.org or pearlcrescent.com)
  --> https://addons.mozilla.org/en-US/firefox/addon/5143
2) Empty cache (View | Clear Private Data...)
3) Open Add-Ons window (Tools | Add-ons)
4) Right click on the extension; choose "Visit Home Page"
5) Instead of seeing the web page I get a "Content Encoding Error" page.

Notes: I don't see this for every add-on so it probably has something to do with the web server that hosts the home page.  In the attached trace, I see a regular request with a Content-Encoding: gzip response followed by a "Range: bytes=0-" request.  The response to the range request is a 206 (Partial Content) response that does not have a Content-Encoding header.

Comment 1

[Boris Zbarsky [:bzbarsky]]

Yeah, we have a check for that exact situation (206 whose content-encoding doesn't match what we have in the cache) and bail out if it happens.  I think we used to corrupt the data instead in Fx2....

Comment 2

[Boris Zbarsky [:bzbarsky]]

Interesting.  We used (in Fx 2) to cancel with NS_ERROR_UNEXPECTED (which just meant a silent failure to load the page) in this situation. Now we cancel with an error code that shows the error page.  Bug 247334 is the original bug in which we introduced the canceling behavior.

I have no idea why you're not seeing this problem in Fx2, other than perhaps that we just ignore the second load silently?

Comment 3

[Kathleen :Brade]

What surprises me about this bug is that the URL loads without error in a browser  window (unless cached in the corrupted state) and an error occurs when the same URL is loaded from the add-ons window.  What is special about loading an URL from the addons window in Firefox 3?

Comment 4

[Boris Zbarsky [:bzbarsky]]

Do we also make two requests for it when loading in a browser window?

Comment 5

[Kathleen :Brade]

(In reply to comment #4)
> Do we also make two requests for it when loading in a browser window?

No, just one.  The first request and response I see when loading from the add-ons window look almost identical to those used when loading in a browser window.  I am going to attach some network logs in case that helps.
> 

Comment 6

[Kathleen :Brade]

Attachment: NSPR_LOG_MODULES=nsHttp:5,nsHostResolver:5 trace when loading from a browser window (successful page load)

Comment 7

[Kathleen :Brade]

Attachment: trace when loading from the add-ons window (Content Encoding Error)

I don't know how to interpret everything in these logs, but this looks odd to me:

-1610559488[5071b0]: Cached data size does not match the Content-Length header [content-length=2286 size=0]

I am not sure, but it looks like the data from the first response did not get inserted into the cache correctly, which leads to the second request (with Range: bytes=0-)

Comment 8

[Boris Zbarsky [:bzbarsky]]

Here's why the data size for the first response is 0 (from the failing log):

-1610559488[5071b0]: nsHttpChannel::ProcessNormal [this=132dade0]
-1610559488[5071b0]: nsHttpChannel::InitCacheEntry [this=132dade0 entry=132db210]
-1610559488[5071b0]: nsHttpResponseHead::MustValidate ??
-1610559488[5071b0]: no mandatory validation requirement
-1610559488[5071b0]: using last-modified to determine freshness-lifetime
-1610559488[5071b0]: last-modified = 1211506768, date = 1212001697
-1610559488[5071b0]: freshnessLifetime = 49492, currentAge = 0
-1610559488[5071b0]:   calling mListener->OnStartRequest
-1610559488[5071b0]: nsHttpHandler::NewURI
-1610559488[5071b0]: nsHttpHandler::NewURI
-1610559488[5071b0]: nsHttpHandler::NewChannel
-1610559488[5071b0]: nsHttpHandler::NewProxiedChannel [proxyInfo=0]
-1610559488[5071b0]: Creating nsHttpChannel @132f6710
-1610559488[5071b0]: nsHttpChannel::Init [this=132f6710]
-1610559488[5071b0]: host=pearlcrescent.com port=-1
-1610559488[5071b0]: uri=http://pearlcrescent.com/products/keywordbox/
-1610559488[5071b0]: Creating nsHttpConnectionInfo @132f60c0
-1610559488[5071b0]: nsHttpChannel::AsyncOpen [this=132f6710]
-1610559488[5071b0]: nsHttpHandler::NotifyObservers [chan=132f673c event="http-on-modify-request"]
-1610559488[5071b0]: nsHttpChannel::Connect [this=132f6710]
-1610559488[5071b0]: nsHttpChannel::OpenCacheEntry [this=132f6710]
-1610559488[5071b0]: nsHttpChannel::Suspend [this=132f6710]
-1610559488[5071b0]: nsHttpChannel::Cancel [this=132dade0 status=804b0002]

Would you be able to breakpoint in that Cancel() call and see who's making it and why?

Comment 9

[Kathleen :Brade]

Attachment: stack at first nsHttpChannel::Cancel() call

Here is the stack trace.  DumpJSStack() says:

0 [native frame]
1 bch_handleContent(request = [xpconnect wrapped (nsISupports, nsIRequest, nsIChannel) @ 0x51d90060 (native @ 0x51d8ea80)], context = [xpconnect wrapped nsIInterfaceRequestor @ 0x51d90020 (native @ 0x51d8d7a0)], contentType = "text/html") ["file:///Users/brade/dev/trunk/mozilla/firefox-debug/dist/MinefieldDebug.app/Contents/MacOS/components/nsBrowserContentHandler.js":545]
    webNavInfo = [xpconnect wrapped nsIWebNavigationInfo @ 0x51d903f0 (native @ 0x4f54d2b0)]
    this = [object Object]

Comment 10

[Boris Zbarsky [:bzbarsky]]

Oh.  So the issue is that the load is initially happening in the add-ons window, then being poor-man's retargeted to a browser window?

Note that there was a change to the JS code in question in 2007.  Is that what changed the behavior to make things not work where they worked in Firefox 2?  Or did we just not hit this code in Firefox 2?

I assume that the UI code does in fact need to be doing what it's doing instead of just relying on our normal content dispatch mechanism...  It seems like a nasty hack that will _always_ make sure we do a load twice if we get to this point....

Comment 11

[Patrick McManus [:mcmanus]]

comment 1..