713400 - irccloud broken by a cache file

Status: RESOLVED INCOMPLETE

(Core :: Networking: Cache, defect)

Description

[Asa Dotzler [:asa]]

I'm not sure if this is Firefox or IRCCloud's fault but one of these cached files seems to be breaking the loading of https://irccloud.com for me. If I clear the cache, everything works. If I restore the cache, IRCCloud loads up a blue screen and the logo and then stops dead.

This started sometime two or three days ago I think. Testing nightly Firefox builds on win7.

I don't know much about how caches work, but is it possible that one of these files should have been invalidated or replaced -- perhaps an old js file that's causing some kind of failure? If that's it, then is our cache to blame for failing to evict?

Here are the items for irccloud listed in about:cache for me.

Key 	Data size 	Fetch count 	Last modified 	Expires
https://irccloud.com/static/favicon.png 	287 bytes 	309 	2011-12-24 10:52:45 	1969-12-31 16:00:00
https://irccloud.com/static/js/dep/backbone-min.js?v=55be0e8a9a0a6831f413a356efd3fa09 	4842 bytes 	26 	2011-12-24 10:52:45 	2012-04-02 10:51:00
https://irccloud.com/static/js/dep/jquery-1.6.2.min.js?v=a1a8cb16a060f6280a767187fd22e037 	32338 bytes 	26 	2011-12-24 10:52:45 	2012-04-02 10:51:00
https://irccloud.com/static/js/dep/underscore-min.js?v=6f6cfe9c37413b6951178ff862e06ffc 	3517 bytes 	26 	2011-12-24 10:52:45 	2012-04-02 10:51:00
https://irccloud.com/static/js/lib/coolclock.js?v=b95019ce064954fe0a5459c25b0c99f2 	9082 bytes 	33 	2011-12-23 21:55:07 	2012-04-01 21:53:21
https://irccloud.com/static/js/lib/date.js?v=7665417eb9ddf1aeacd3466d7637cce0 	30638 bytes 	33 	2011-12-23 21:55:07 	2012-04-01 21:53:21
https://irccloud.com/static/js/lib/debug.js?v=65c0b5cbb8094d3d95885a27dd7ae664 	9193 bytes 	33 	2011-12-23 21:55:06 	2012-04-01 21:53:21
https://irccloud.com/static/js/lib/jquery-ui-1.8.9.custom.min.js?v=738e5a7bc2057eb31e87201eb183485a 	31838 bytes 	33 	2011-12-23 21:55:06 	2012-04-01 21:53:21
https://irccloud.com/static/js/lib/jquery.timeago.js?v=5ca7c7c5986feafeebd5bebd477bab58 	5578 bytes 	33 	2011-12-23 21:55:06 	2012-04-01 21:53:21
https://irccloud.com/static/js/lib/util.js?v=eadbbeda1efc8226964ddfb79429d01a 	3523 bytes 	33 	2011-12-23 21:55:06 	2012-04-01 21:53:22
https://irccloud.com/static/LAB.js 	2236 bytes 	26 	2011-12-24 10:52:45 	1969-12-31 16:00:00
https://irccloud.com/static/logo.png 	2938 bytes 	26 	2011-12-24 10:52:45 	1969-12-31 16:00:00
https://irccloud.com/static/main.css?v=047dc564707e172ff88c9a82d6a71830 	10262 bytes 	26 	2011-12-24 10:52:44 	2012-04-02 10:50:59
https://irccloud.com/static/screenshot-thumb-20110217.png 	145163 bytes 	26 	2011-12-24 10:52:45 	1969-12-31 16:00:00

Comment 1

[James Wheare]

Those versioned files are all the current and correct version. We make sure to cachebust everything whenever we make a front end deploy, and we haven't done so in a while, the cache may be a red herring. Are there any errors in the JS console when you get the blank page? What does the log output look like?

Comment 2

[Asa Dotzler [:asa]]

No errors in the console. If I put those files in my cache, IRCCloud fails to load. If I take them out of my cache, IRCCloud works as expected. I've tried this on a completely new Firefox profile with no extensions on a stock Windows 7 machine.

Comment 3

[James Wheare]

Any output in the console at all? Sounds like none of the Javascript is getting executed? If LAB.js fails to load that would happen. Can you check what's happening with a step debugger?

Comment 4

[Bjarne (:bjarne)]

I can not reproduce this on Linux with an opt nor a debug build from today. However, in the log from the debug-build I see the following on the second load

678426368[7fca3b526bf0]: nsHttpTransaction::HandleContent [this=18a47280 count=20]
678426368[7fca3b526bf0]: nsHttpTransaction::HandleContentStart [this=18a47280]
678426368[7fca3b526bf0]: http response [
678426368[7fca3b526bf0]:   HTTP/1.1 304 Not Modified
678426368[7fca3b526bf0]:   Content-Encoding: gzip
678426368[7fca3b526bf0]:   Date: Mon, 26 Dec 2011 20:54:55 GMT
678426368[7fca3b526bf0]:   Server: misultin/0.9-dev
678426368[7fca3b526bf0]:   Connection: Keep-Alive
678426368[7fca3b526bf0]:   Content-Length: 20
678426368[7fca3b526bf0]: ]
678426368[7fca3b526bf0]: nsHttpConnection::OnHeadersAvailable [this=7fca1f662fa0 trans=7fca18a47280 response-head=7fca19cbc1f0]
678426368[7fca3b526bf0]: Connection can be reused [this=1f662fa0 idle-timeout=115]
678426368[7fca3b526bf0]: this response should not contain a body.
678426368[7fca3b526bf0]: nsHttpTransaction::HandleContent [this=18a47280 count=20 read=0 mContentRead=0 mContentLength=0]
678426368[7fca3b526bf0]: nsHttpConnection::PushBack [this=7fca1f662fa0, length=20]
678426368[7fca3b526bf0]: ###!!! ASSERTION: nsHttpConnection::PushBack only one buffer supported: 'Error', file /home/bjarne/Work/Mozilla/Trunk/mozilla-central/netwerk/protocol/http/nsHttpConnection.cpp, line 787
678426368[7fca3b526bf0]: nsHttpConnection::CloseTransaction[this=1f662fa0 trans=18a47280 reason=80470002]
678426368[7fca3b526bf0]: nsHttpTransaction::Close [this=18a47280 reason=0]
678426368[7fca3b526bf0]: nsHttpConnectionMgr::ReclaimConnection [conn=1f662fa0]

Note the assertion and 3 lines above which indicates that the 304 has a body - seems to happen for two resources: LAB.js and lock.png.

The assertion is related to re-using connections (pushing back data). There was a change to nsHttpConnection.cpp about a week ago (bug #631801) which affected the combination of https and re-use. And the last factor is that 304 can only be received if the resource is already cached. Since I cannot reproduce, I cannot check if the change from bug #631801 causes this but maybe someone else can?

Comment 5

[James Wheare]

For what it's worth, the ?v= parameter only serves as a cachebuster. You can't request different versions of the files by changing it. So reproducing this may be tricky because you'd have to reproduce Asa's complete cache state. Is there a chance one of the files in cache got corrupted somehow? Can you read out the contents of those cached files and upload them to a pastebin or something?

Comment 6

[Bjarne (:bjarne)]

I got the impression that this if reproducible if I clear my cache, load the page once and then load it again...?  I don't assume that

In reply to Asa Dotzler [:asa] from comment #2)
> If I put those files in my cache

means that the files or cache-directory are *copied*...?

Comment 7

[James Wheare]

If it were as simple as that to reproduce I imagine we would have received *many* more bug reports from everyone visiting the site with a clean cache. This is the only report I've seen.

Comment 8

[Bjarne (:bjarne)]

So, the hypothesis is that it is the reporters copy of some files which fails? Do you have many FF-nightly users on irccloud? Reporter: Any input on how to reproduce?

Comment 9

[Patrick McManus [:mcmanus]]

(In reply to Bjarne (:bjarne) from comment #4)
> The assertion is related to re-using connections (pushing back data).

pushback is only tangentially about re-using connections. The assertion is that somehow we managed to overread more than 1 buffer worth of data from a connection - that should never happen even if there is data associated with a no-content response (which would be a server bug but one we encounter and deal with all the time.)

it is not directly related to the canreuse change - that codepath comes in later after this assertion has already happened. It should probably be an abort actually - the complaint about more than 1 buffer is a code error not a data error.

I'm on break and traveling until after the new year.. not sure if my traveling laptop is up to the debugging challenge in the interim.

Comment 10

[James Wheare]

(In reply to Bjarne (:bjarne) from comment #8)
> Do you have many FF-nightly users on irccloud?
We have a few, none of whom have reported a similar issue.

Comment 11

[Patrick McManus [:mcmanus]]

re comment 9 (and comment 4) please see bug 714669 to correct the assertion. That issue is basically harmless and is not the root cause of this bug so I haven't marked it as a dependency.