381812 - Extension download fails with error -228 when xpi is ssl hosted and can be cached

Status: RESOLVED FIXED

(Core :: Networking: HTTP, defect)

Description

[Sam Quigley]

User-Agent:       Mozilla/5.0 (Macintosh; U; Intel Mac OS X; en-US; rv:1.8.1.3) Gecko/20070309 Firefox/2.0.0.3
Build Identifier: Mozilla/5.0 (Macintosh; U; Intel Mac OS X; en-US; rv:1.8.1.3) Gecko/20070309 Firefox/2.0.0.3

When installing an extension from our site, Firefox first displays the "You have asked to install the following item" popup.  If the user clicks "install", the download fails with a "Download Failed / Error Code -228" message.  

It turns out that FF is issuing two requests: first, a normal GET (our server returns 200 and an Etag), and then a GET with a "Range: bytes=0-" header.  Firefox chokes on the 206 sent in response to the second.  When I mimic the two requests using curl, the downloaded files are identical, and by my reading of the HTTP spec, the 206 response is correct.  However, if I unset the "Accept-Ranges" header in Apache, Firefox does not send a "Range:" in the 2nd request, and the XPI downloads and installs correctly.

The server in question is Apache 2.0.54; I've attached a sanitized copy of the headers sent during this exchange below.  The xpi is hosted on an https url, though I'm not sure why that'd be relevant.

Reproducible: Always

Steps to Reproduce:
1. Click an xpi link on a server that supports Accept-Ranges HTTP header
2. Click install

Actual Results:  
Error Code -228 message appears

Expected Results:  
Add-on should download and install correctly

This is a copy of the HTTP headers sent during the exchange.  (Recorded with the Live HTTP headers extension.)

https://www.site.com/path/extension.xpi

GET /path/extension.xpi HTTP/1.1
Host: www.site.com
User-Agent: Mozilla/5.0 (Macintosh; U; Intel Mac OS X; en-US; rv:1.8.1.3) Gecko/20070309 Firefox/2.0.0.3
Accept: text/xml,application/xml,application/xhtml+xml,text/html;q=0.9,text/plain;q=0.8,image/png,*/*;q=0.5
Accept-Language: en-us,en;q=0.5
Accept-Encoding: gzip,deflate
Accept-Charset: ISO-8859-1,utf-8;q=0.7,*;q=0.7
Keep-Alive: 300
Connection: keep-alive

HTTP/1.x 200 OK
Date: Wed, 23 May 2007 23:00:19 GMT
Server: Apache
Last-Modified: Tue, 22 May 2007 17:50:00 GMT
Etag: "560a85-21d04-adafe200"
Accept-Ranges: bytes
Content-Length: 138500
Vary: User-Agent
Connection: close
Content-Type: application/x-xpinstall
----------------------------------------------------------
https://www.site.com/path/extension.xpi

GET /path/extension.xpi HTTP/1.1
Host: www.site.com
User-Agent: Mozilla/5.0 (Macintosh; U; Intel Mac OS X; en-US; rv:1.8.1.3) Gecko/20070309 Firefox/2.0.0.3
Accept: text/xml,application/xml,application/xhtml+xml,text/html;q=0.9,text/plain;q=0.8,image/png,*/*;q=0.5
Accept-Language: en-us,en;q=0.5
Accept-Encoding: gzip,deflate
Accept-Charset: ISO-8859-1,utf-8;q=0.7,*;q=0.7
Keep-Alive: 300
Connection: keep-alive
Range: bytes=0-
If-Range: "560a85-21d04-adafe200"

HTTP/1.x 206 Partial Content
Date: Wed, 23 May 2007 23:00:20 GMT
Server: Apache
Last-Modified: Tue, 22 May 2007 17:50:00 GMT
Etag: "560a85-21d04-adafe200"
Accept-Ranges: bytes
Content-Length: 138500
Vary: User-Agent
Content-Range: bytes 0-138499/138500
Connection: close
Content-Type: application/x-xpinstall
----------------------------------------------------------
https://www.site.com/path/extension.xpi

GET /path/extension.xpi HTTP/1.1
Host: www.site.com
User-Agent: Mozilla/5.0 (Macintosh; U; Intel Mac OS X; en-US; rv:1.8.1.3) Gecko/20070309 Firefox/2.0.0.3
Accept: text/xml,application/xml,application/xhtml+xml,text/html;q=0.9,text/plain;q=0.8,image/png,*/*;q=0.5
Accept-Language: en-us,en;q=0.5
Accept-Encoding: gzip,deflate
Accept-Charset: ISO-8859-1,utf-8;q=0.7,*;q=0.7
Keep-Alive: 300
Connection: keep-alive
Range: bytes=0-
If-Range: "560a85-21d04-adafe200"

HTTP/1.x 206 Partial Content
Date: Wed, 23 May 2007 23:00:28 GMT
Server: Apache
Last-Modified: Tue, 22 May 2007 17:50:00 GMT
Etag: "560a85-21d04-adafe200"
Accept-Ranges: bytes
Content-Length: 138500
Vary: User-Agent
Content-Range: bytes 0-138499/138500
Connection: close
Content-Type: application/x-xpinstall
----------------------------------------------------------

Comment 1

[Dave Townsend [:mossop]]

Can you please give us the url to your site so that we can test this. This certainly isnt a problem with https or sites that support accept-ranges (most sites including I believe addons.mozilla.org does both). Also you might try clearing your internet cache just to rule out a bad previous download.

I find it interesting that the second request starts from 0, the normal procedure is for firefox to download a small chunk of the file to check whether the xpi is signed and then to download the remaining. That the second request starts from 0 suggests it didn't get any data in the first request I think.

Comment 2

[Sam Quigley]

Sorry, I should have mentioned that we've resolved this on our server (by blocking the Accept-Ranges header in Apache) -- so it's no longer reproducible on our site.  Given that this was affecting a number of our users, I don't think we can undo our fix for testing purposes, but I'll see if I can reproduce it elsewhere.

The Apache instance is a fairly normal installation of the apache2 package in Debian Sarge.

For what it's worth, this is what the headers look like now (without Accept-Ranges):

https://www.site.com/path/extension.xpi

GET /path/extension.xpi HTTP/1.1
Host: www.site.com
User-Agent: Mozilla/5.0 (Macintosh; U; Intel Mac OS X; en-US; rv:1.8.1.3) Gecko/20070309 Firefox/2.0.0.3
Accept: text/xml,application/xml,application/xhtml+xml,text/html;q=0.9,text/plain;q=0.8,image/png,*/*;q=0.5
Accept-Language: en-us,en;q=0.5
Accept-Encoding: gzip,deflate
Accept-Charset: ISO-8859-1,utf-8;q=0.7,*;q=0.7
Keep-Alive: 300
Connection: keep-alive

HTTP/1.x 200 OK
Date: Thu, 24 May 2007 10:04:01 GMT
Server: Apache
Last-Modified: Thu, 24 May 2007 02:16:24 GMT
Etag: "560a63-21d04-de8e4e00"
Content-Length: 138500
Vary: User-Agent
Connection: close
Content-Type: application/x-xpinstall
----------------------------------------------------------
https://www.site.com/path/extension.xpi

GET /path/extension.xpi HTTP/1.1
Host: www.site.com
User-Agent: Mozilla/5.0 (Macintosh; U; Intel Mac OS X; en-US; rv:1.8.1.3) Gecko/20070309 Firefox/2.0.0.3
Accept: text/xml,application/xml,application/xhtml+xml,text/html;q=0.9,text/plain;q=0.8,image/png,*/*;q=0.5
Accept-Language: en-us,en;q=0.5
Accept-Encoding: gzip,deflate
Accept-Charset: ISO-8859-1,utf-8;q=0.7,*;q=0.7
Keep-Alive: 300
Connection: keep-alive

HTTP/1.x 200 OK
Date: Thu, 24 May 2007 10:04:01 GMT
Server: Apache
Last-Modified: Thu, 24 May 2007 02:16:24 GMT
Etag: "560a63-21d04-de8e4e00"
Content-Length: 138500
Vary: User-Agent
Connection: close
Content-Type: application/x-xpinstall
----------------------------------------------------------
https://www.site.com/path/extension.xpi

GET /path/extension.xpi HTTP/1.1
Host: www.site.com
User-Agent: Mozilla/5.0 (Macintosh; U; Intel Mac OS X; en-US; rv:1.8.1.3) Gecko/20070309 Firefox/2.0.0.3
Accept: text/xml,application/xml,application/xhtml+xml,text/html;q=0.9,text/plain;q=0.8,image/png,*/*;q=0.5
Accept-Language: en-us,en;q=0.5
Accept-Encoding: gzip,deflate
Accept-Charset: ISO-8859-1,utf-8;q=0.7,*;q=0.7
Keep-Alive: 300
Connection: keep-alive

HTTP/1.x 200 OK
Date: Thu, 24 May 2007 10:04:06 GMT
Server: Apache
Last-Modified: Thu, 24 May 2007 02:16:24 GMT
Etag: "560a63-21d04-de8e4e00"
Content-Length: 138500
Vary: User-Agent
Connection: close
Content-Type: application/x-xpinstall
----------------------------------------------------------

Comment 3

[Sam Quigley]

Oh, I should also say that I did try clearing my cache, setting my cache to > 50 MB, restarting Firefox, and using a new, empty profile while I was attempting to debug this issue.  None of those steps helped the issue.

-sq

Comment 4

[Eric Waters]

This problem affects not just the initial download of the xpi extension, but also the update.rdf retrieval.  These fail with an unknown error.  Appears to be a bug as of FF 2.0.0.1; FF 2.0 works fine.

A live site that one can try this on is:  https://blueimp.net/mozilla/Autofill%20Forms/

Clicking the "Install now" link will fail in 2.0.0.4 with a -228 download error.  I've tested this in new profiles on Linux with FF 2.0, 2.0.0.[1-4].

Comment 5

[Dave Townsend [:mossop]]

Thanks Eric, I can confirm that I see the same issue. I'll be investigating this further over the next few days, if you could let me know if you make any changes to the server config or extension that might affect this please let me know.

Comment 6

[Gregr]

(In reply to comment #1)
> Can you please give us the url to your site so that we can test this. This
> certainly isnt a problem with https

Some additional info here, hope this helps.
I'm not sure that's not a http/https pb.
The same .xpi served by 2 different Apache :

-The one with ssl gives "error -228" with 
Range: bytes=0
-On the "normal" one, the extension is installing successfully with
Range: bytes=4096
on the second request

Mozilla/5.0 (X11; U; Linux i686; en-US; rv:1.8.1.4) Gecko/20061201 Firefox/2.0.0.4 (Ubuntu-feisty)

Comment 7

[Jakub Żytka]

I've got similar problem. If you want to test:
https://www.kormoran.net/smetnywij/kurnikplus/kurnikplus_1030.xpi

However, i found some simple workaround. Instead of serving xpi i use a cgi script:
#!/usr/bin/python

import os
xpi = file(xpiFileName, "rb")
stat = os.stat(xpiFileName);
print 'Content-Type: application/x-xpinstall'
print 'Content-Length:', stat.st_size
print
print xpi.read()

this script is located here:
https://www.kormoran.net/smetnywij/kurnikplus/kurnikplus_1030.cgi

Using cgi solves the "228" error.
I believe this suggests that indeed some http headers are involved...

Comment 8

[Dave Townsend [:mossop]]

I'm now able to reproduce this around 25% of the time, the problem appears to lie somewhere in the cache. If the xpi is marked uncachable by the server (something the cgi script from comment 7 would do) then the error does not appear to arise.

Comment 9

[Dave Townsend [:mossop]]

Attachment: NSPR log of a failed download

This is a full trace of nsHttp logging from the start of the xpi request to the failure.

The problem appears to stem from some just before the start of the last request:

> -1610559488[1e070f0]: got cache entry [access=3]
> -1610559488[1e070f0]: nsHTTPChannel::CheckCache [this=3acd2820 entry=3acd2c30]
> -1610559488[1e070f0]: nsHttpResponseHead::Parse [this=3acd2b20]
> -1610559488[1e070f0]: nsHttpResponseHead::ParseVersion [version=HTTP/1.1 200 OK]
> -1610559488[1e070f0]: Have status line [version=11 status=200 statusText=OK]
> -1610559488[1e070f0]: ParseContentType [type=application/x-xpinstall]
> -1610559488[1e070f0]: Cached data size does not match the Content-Length header [content-length=495 size=0]

Finding the cached entry is too small the channel attempts a partial request (unnecessary really since there is no data at all)

Then once this has been retrieved the channel is started again to retrieve the now cached data:

> -1610559488[1e070f0]: nsHttpChannel::OnStartRequest [this=3acd2820 request=3ace2ba0 status=c1f30001]

That status is NS_ERROR_NOT_INITIALIZED and comes from the status of the request passed in to OnStartRequest, the request appears to be the inputstreampump created here: http://bonsai.mozilla.org/cvsblame.cgi?file=/mozilla/netwerk/protocol/http/src/nsHttpChannel.cpp&rev=1.315&mark=1862#1857

Given that we are not hitting all sorts of issues with ssl pages this has to have something to do with how xpi downloads are passed off to xpinstall. When the content type application/x-xpinstall is detected the channel reading it is cancelled so xpinstall can start it's own channel. I wonder if this is messing up the cache somehow?

This is backed up by me being unable to reproduce this issue if I use InstallTrigger.install to start an xpi install which make xpinstall start the request itself rather than going through the normal route.

Comment 10

[Dave Townsend [:mossop]]

Attachment: NSPR log of a successful download

For reference this is a similar log but of a download that succeeded. There are a few differences along the way, but mainly the cache access received is WRITE whereas in the previous example it was READ_WRITE so the channel never attempts to use data out of a partial cache entry and so the final request is a full request.

Comment 11

[Dave Townsend [:mossop]]

Since we are attempting to move extension authors to more secure methods of hosting their extensions (bug 378216) this really needs to get looked at.

Comment 12

[Benjamin Smedberg]

bz says he remembers a bug like this cross his reviews recently, but can't find it

Comment 13

[Boris Zbarsky [:bzbarsky]]

I was thinking bug 386233, for what it's worth.

Comment 14

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

the error is from:
http://lxr.mozilla.org/seamonkey/source/xpcom/io/nsStorageStream.cpp#387

so, this requires that the 0-byte cache entry is from the memory cache.

Comment 15

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

Attachment: patch

Comment 16

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

Checking in nsStorageStream.cpp;
/cvsroot/mozilla/xpcom/io/nsStorageStream.cpp,v  <--  nsStorageStream.cpp
new revision: 1.35; previous revision: 1.34
done

Comment 17

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

Attachment: patch for testcase

improves the testcase (note: I also checked in a bustage fix for the testcase, which used to test the previous behaviour that reading throws)

Comment 18

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

Comment on attachment 277150 [details] [diff] [review]
patch for testcase

Checking in xpcom/tests/unit/test_storagestream.js;
/cvsroot/mozilla/xpcom/tests/unit/test_storagestream.js,v  <--  test_storagestream.js
new revision: 1.3; previous revision: 1.2
done

Comment 19

[Jürgen Körner]

Hi there! Struggled with the -228 for quite a while, did all the recommended . Found this discussion group showing I am not the only one... But the comments above sound all "Greek" / "Geek" to me :-) Is there any progress here, do I have to install some "script"? Thanks

Comment 20

[Jürgen Körner]

Hi there! Struggled with the -228 for quite a while, did all the recommended stuff. Found this discussion group showing I am not the only one... But the comments above sound all "Greek" / "Geek" to me :-) Is there any progress here, do I have to install some "script"? Thanks

Comment 21

[Brett Zamir]

In Apache, adding the following to htaccess worked to solve this problem for me in FF2:

<FilesMatch "\.(xpi)$">
Header unset Cache-Control
Header unset Expires
Header unset Last-Modified
FileETag None
Header unset Pragma
</FilesMatch>