1261440 - 304 threading regression

Status: RESOLVED INCOMPLETE

(Core :: Networking: Cache, defect)

Description

[[e-mail]]

User Agent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10.11; rv:45.0) Gecko/20100101 Firefox/45.0
Build ID: 20160315153207

Steps to reproduce:

1) 4 iframes sharing one css file with a one minute expires header.
2) firefox sends "If modified since" for the css of only one iframe due to concurrency.
(that's ok but you may need a bunch of external resources to get one or more of the css files to be requested after at least one is returned so that the "If modified since" is sent)
3) 304 is returned from the server but firefox acts like it can't get the css from cache.



Actual results:

no css in one iframe unless caching is disabled in the developer tools of firefox.


Expected results:

The css should be guaranteed as retrievable from cache before an "If modified since" header is sent, it should then be locked in the cache to prevent removal until after the request completes with a 200, 304, or timeout.

Comment 1

[Loic]

Could provide a live testcase, please.

Comment 2

[Michal Novotny [:michal]]

Or provide NSPR log (https://developer.mozilla.org/en-US/docs/Mozilla/Debugging/HTTP_logging). Use NSPR_LOG_MODULES=timestamp,nsHttp:5,cache2:5

Comment 3

[[e-mail]]

Attachment: test log

Comment 4

[Honza Bambas (:mayhemer)]

(In reply to elatllat from comment #3)
> Created attachment 8740621 [details]
> test log

Please use these exact modules:

NSPR_LOG_MODULES=timestamp,nsHttp:5,cache2:5


this log is useless...

Comment 5

[[e-mail]]

Sorry I unset that by blindly following the instructions in the link.
Attaching a log with the correct NSPR_LOG_MODULES now.
This log is a little longer as it took me a few refreshes to reproduce the issue.

Comment 6

[[e-mail]]

Attachment: test log with the requested modules

Comment 7

[Honza Bambas (:mayhemer)]

For all instances of http://192.168.0.112:88/test13.css I can see:

CacheEntry::SetPredictedDataSize [this=11d1e9ba0] too big, dooming

Seems like you have changed the browser.cache.disk.max_entry_size preference value, probably to zero?

If you can reproduce with a fresh profile, please reopen.

Comment 8

[[e-mail]]

  about:config
said that 
  browser.cache.disk.max_entry_size, default, integer, 51200
but I'll test on a fresh profile anyway.

Comment 9

[[e-mail]]

I was able to reproduce this with a fresh profile.

I did change
    about:preferences#advanced
    Limit cache to 0MB
to reduce the log size and speed of reproduction.

Comment 10

[[e-mail]]

Attachment: ff_clean_log.txt.7z

Comment 11

[Michal Novotny [:michal]]

(In reply to elatllat from comment #9)
> I was able to reproduce this with a fresh profile.
> 
> I did change
>     about:preferences#advanced
>     Limit cache to 0MB
> to reduce the log size and speed of reproduction.

By doing this you disabled the cache, so you cannot expect to successfully load the resource from the cache.

Comment 12

[[e-mail]]

I made another clean profile and browsed the web until the default 350MB was full then was able to reproduce the issue. It seems to makes no difference how big the disk cache is, when you hit it's limit Firefox should manage resources so web pages can be displayed properly;
aka Don't send a "if modified since" header unless it's willing to keep the local resource until there is an answer or timeout. Let me know if you want me to upload the 5GB log file somewhere.

Comment 13

[Valentin Gosu [:valentin] (he/him)]

elatllat, I assume the 5GB log file also includes you navigating to fill up the cache, right? If so, we don't need all of it. You can probably try to reproduce it again, and upload the log files to any file sharing service, and post the link.
Michal, can you take this after elatllat posts the log file?

Comment 14

[Michal Novotny [:michal]]

We don't have enough information to analyze or fix the problem.