748647 - INHIBIT_PERSISTENT_CACHING is incorrectly propagated after a redirect

Status: RESOLVED FIXED

(Core :: Networking: Cache, defect)

Description

[Jason Stubbs]

User Agent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_7_3) AppleWebKit/535.19 (KHTML, like Gecko) Chrome/18.0.1025.163 Safari/535.19

Steps to reproduce:

1. Access http://www.mozilla.org/ (which redirects to http://www.mozilla.org/en-US/)
2. Close Firefox
3. Open Firefix
4. Open a tool that traces requests (I'm using "Live HTTP headers" Generator view)
5. Access http://www.mozilla.org/


Actual results:

All of the images and such that should be served from cache are re-requested from the server without even using If-Modified-Since headers.


Expected results:

Local cache should be used to serve requests.

Everything works fine when accessing http://www.mozilla.org/en-US/ directly. The problem only seems to occur after a redirect - and only on the first access after opening Firefox.

Comment 1

[Jason Stubbs]

Oh, and I forgot to mention that FF11 doesn't have this problem so it looks to be a regression.

Comment 2

[Matthias Versen [:Matti]]

You should avoid an addon if possible. I used wireshark and I can confirm that the request for the image is without If-Modified-Since header

GET /media/img/home/promo-contribute.jpg HTTP/1.1
Host: www.mozilla.org
User-Agent: Mozilla/5.0 (Windows NT 6.1; rv:12.0) Gecko/20100101 Firefox/12.0
Accept: image/png,image/*;q=0.8,*/*;q=0.5
Accept-Language: en-us,en;q=0.5
Accept-Encoding: gzip, deflate
Connection: keep-alive
Referer: http://www.mozilla.org/en-US/
Cookie: WT_FPC=id=87.151.206.180-3872242880.30220970:lv=1335327368868:ss=1335327368868

Comment 3

[Jason Stubbs]

Yep, if I was the only one with the problem I would ordinarily disable all addons to confirm that it wasn't something there, but I've got a bunch of servers that are working very hard since FF12's release. ;)

Just in case I wasn't clear, FF11 serves the request directly from the cache without going to the server at all. FF12 behaves the same when accessing http://www.mozilla.org/en-US/ directly. It's only when the page is loaded after a redirect that the cache isn't used.

Comment 4

[Patrick McManus [:mcmanus]]

I can confirm this on FF15.. potentially a important item - thanks Jason Stubbs!

Comment 5

[Jason Stubbs]

As soon as I get a chance, I'll figure out how to use mecurial and its bisect command to track down what changed and then see if I can fix it, but if there's anybody free to look at it earlier I'd be very grateful. For us, it's more than potentially important as it's actually costing us around $120/day in extra bandwidth usage.

Reading over my report again, it probably wasn't clear that it's not the first request after opening the browser, but affects each and every URL the first time that URL is requested after opening the browser. That is, in my initial list of steps to reproduce, accessing www.google.com, www.yahoo.com, etc between steps 3 and 5 still leads to the same behaviour at step 5.

Comment 6

[Jason Stubbs]

Doing a bisect between AURORA_BASE_20111220 and FIREFOX_12_0_RELEASE, the regression first surfaces with the following commit:

changeset:   88544:4b7d5b27dd5f
user:        Michal Novotny <[e-mail]>
date:        Mon Jan 30 18:03:52 2012 +0100
summary:     Bug 649778 - document.write may cause a document to be written to disk cache even when the page has Cache-Control: no-store

https://hg.mozilla.org/mozilla-central/rev/4b7d5b27dd5f

Comment 7

[Jason Stubbs]

This code is a little too complex for me to be confident in fixing it without introducing other bugs, but I can confirm that the following change does fix the issue. I have to wonder though, perhaps the real problem is actually that these attributes are being propagated at all? Like I said, I think this code may be a little too complex for a drive by patching. ;)

diff -r 4b7d5b27dd5f netwerk/protocol/http/nsHttpChannel.cpp
--- a/netwerk/protocol/http/nsHttpChannel.cpp	Mon Jan 30 18:03:52 2012 +0100
+++ b/netwerk/protocol/http/nsHttpChannel.cpp	Mon May 07 11:01:08 2012 +1000
@@ -1047,6 +1047,7 @@
 #if 0
     case 305: // disabled as a security measure (see bug 187996).
 #endif
+        mLoadFlags &= ~INHIBIT_PERSISTENT_CACHING;
         // don't store the response body for redirects
         MaybeInvalidateCacheEntryForSubsequentGet();
         PushRedirectAsyncFunc(&nsHttpChannel::ContinueProcessResponse);

Comment 8

[Lukas Blakk [:lsblakk] use ?needinfo]

Tracking this regression and passing over to bz in the hopes that he can assign someone to look into this.

Comment 9

[Boris Zbarsky [:bzbarsky]]

I can't exactly assign anyone to work on anything; I can just nag...

I don't understand why bug 649778 would have affected this, though.  Why are the sub-resources even being redirected?  Who's setting the INHIBIT_PERSISTENT_CACHING flag?

Honza, maybe you know something about this?

Comment 10

[Jason Stubbs]

I'm still looking into this as well, although I'm hitting walls in trying to understand the code. I'll brain dump what I've figured out so far though...

- The "Cache-Control: no-store ..." header on the 301/302 response is what's causing INHIBIT_PERSISTENT_CACHING to be set
- The fix for bug #649778 introduced a UpdateInhibitPersistentCachingFlag() function and calls it in several places that weren't called previously
- One of these is at the top of ProcessResponse(), which ends up setting the flag on a whole lot of responses where it wasn't before
- HttpBaseChannel::SetupReplacementChannel() then propagates this flag to the channel for the redirected url
- I tried doing a few "hg annotate" calls to figure out why the flag is propagated in SetupReplacementChannel(), but the code already existed in the import from CVS... 
- That then some how ends of as part of the flags of the "load group" and is applied to all images, css, etc.

And my thoughts on the above...

- As UpdateInhibitPersistentCachingFlag() at the top of ProcessResponse(), I'd think that all the other calls would be redundant
- INHIBIT_PERSISTENT_CACHING seems to mean different things in different contexts
- Stripping the flag in SetupReplacementChannel() regardless of SSL feels like the right fix to me, but I don't understand why that code was initially there

Comment 11

[Jason Stubbs]

Oh, and one more thought I had... Are any of the changes to netwerk/protocol/http/nsHttpChannel.cpp in the bug #649778 patch actually necessary? I haven't tested it but, looking at the code, only the changes in content/html/document/src/nsHTMLDocument.cpp seem to be relevant.

Comment 12

[Honza Bambas (:mayhemer)]

I'll look into this today.  I was reviewing the patch and all seemed to me reasonable.  I have to recheck.

Comment 13

[Honza Bambas (:mayhemer)]

Attachment: v1

Before the patch for bug 649778 we were setting the INHIBIT_PERSISTENT_CACHING flag on the original channel after we created the new channel for redirect target and propagated the flag (if set) to it.  The flag was not being set when creating the target channel (solely on no-store) before the patch.

Now, we set INHIBIT_PERSISTENT_CACHING right before we even decide on the response code - in nsHttpChannel::ProcessResponse().

I moved UpdateInhibitPersistentCachingFlag() call from ProcessResponse() to ContinueProcessNormal(), after we create the redirect target channel but before we set storage policy on cache entry.

The test passes for this change and I see 304 responses on the second www.mozilla.org load for all images and don't see INHIBIT_PERSISTENT_CACHING would propagate to the redirect channel.

To explain why this bug happens: load group is using the default's request (the page's) load flags.  Load group's load flags then propagate to image subrequests, and therefor are not cached.

Comment 14

[Honza Bambas (:mayhemer)]

Comment on attachment 621959 [details] [diff] [review]
v1

https://tbpl.mozilla.org/?tree=Try&rev=54a05280d316

Comment 15

[Jason Stubbs]

I can confirm that works. For what it's worth, it makes sense to me too - although I still haven't figured out exactly what a channel represents.
Thanks for looking at it, and apologies if I was getting too noisy. :)

Comment 16

[Honza Bambas (:mayhemer)]

(In reply to Jason Stubbs from comment #15)
> Thanks for looking at it, and apologies if I was getting too noisy. :)

Thanks for the report!  You were noisy exactly as you had to be ;)

Comment 17

[Alex Keybl [:akeybl]]

Is this caching problem the same as bug 751753?

Comment 18

[Matthias Versen [:Matti]]

This is AFAIK the opposite of bug 751753. This one is about not caching while bug 751753 is about too aggressive caching.

Comment 19

[Jason Stubbs]

I don't understand why but after reproducing bug 751753 using the info in comment 5, I can confirm that the patch in this bug does indeed fix it. Will comment further on the other bug.

Comment 20

[Honza Bambas (:mayhemer)]

Comment on attachment 621959 [details] [diff] [review]
v1

https://hg.mozilla.org/mozilla-central/rev/20bed1f4d9a1

Comment 23

[Alex Keybl [:akeybl]]

Is this fix low risk enough to uplift to mozilla-aurora/beta?

Comment 24

[Alex Keybl [:akeybl]]

Comment on attachment 621959 [details] [diff] [review]
v1

Spoke with Honza over email - approving for Aurora 14 and Beta 13 as well.

Comment 25

[Honza Bambas (:mayhemer)]

Comment on attachment 621959 [details] [diff] [review]
v1

https://hg.mozilla.org/releases/mozilla-aurora/rev/8edbfdefcc26
https://hg.mozilla.org/releases/mozilla-beta/rev/e07394da6e8b

Comment 26

[Jason Stubbs]

Any chance of a 12.0.1?

Comment 28

[Josh Aas]

(In reply to Jason Stubbs from comment #26)
> Any chance of a 12.0.1?

No. Firefox 13 will address this issue, it's scheduled to be released soon (June 5th, iirc). I encourage anyone who can't wait to try Firefox Beta, which already has the fix.

Comment 29

[Virgil Dicu [:virgil] [QA]]

Mozilla/5.0 (Macintosh; Intel Mac OS X 10.6; rv:13.0) Gecko/20100101

Verified on Mac OS 10.6 in F13b6 using STR from comment 0.
Images from mozilla.org are now retrieved from cache using If-now headers (after restart).


http://www.mozilla.org/media/js/common-min.js?build=7fbd288

GET /media/js/common-min.js?build=7fbd288 HTTP/1.1
Host: www.mozilla.org
User-Agent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10.6; rv:13.0) Gecko/20100101 Firefox/13.0
Accept: */*
Accept-Language: en-us,en;q=0.5
Accept-Encoding: gzip, deflate
Connection: keep-alive
Referer: http://www.mozilla.org/en-US/
Cookie: WT_FPC=id=188.27.147.153-758141552.30227863:lv=1338359113477:ss=1338359055395; wtspl=75575; Firefox8WhatsNewSurvey=no; dloadday=188.27.147.153.1338369821285836
If-Modified-Since: Wed, 02 May 2012 00:02:32 GMT
If-None-Match: "17780"

HTTP/1.1 304 Not Modified
Date: Wed, 30 May 2012 09:25:22 GMT
X-Cache-Info: cached

Comment 30

[Virgil Dicu [:virgil] [QA]]

Mozilla/5.0 (Macintosh; Intel Mac OS X 10.6; rv:14.0) Gecko/20100101

Verified in Firefox 14 beta 7 and Aurora 15 on Mac OS 10.6.