Closed Bug 614039 Opened 12 years ago Closed 11 years ago

User sees only _CACHE_ files in Cache dir, and cache reports it's full

Categories

(Core :: Networking: Cache, defect)

Product:
Core
Component:
Networking: Cache
Version:
1.9.2 Branch
Platform:
x86
Windows XP
Type:
defect
Priority:
Not set
Severity:
normal

Tracking

()

Status:
RESOLVED DUPLICATE of bug 443067

People

(Reporter: jduell.mcbugs, Unassigned)

References

(Blocks 1 open bug)

Details

From 

http://groups.google.com/group/mozilla.dev.apps.firefox/browse_thread/thread/b836dfbc15b0dcd8#

> I am periodically running into a situation where "storage in use" is at a
> max but there is nothing in the cache folder aside from the four _CACHE_
> files.  At that point nothing new will ever be cached, presumably.
>
> At the moment the cache folder is not empty, but its size is out of sync (by
> 50 mib) with "storage in use" that about:cache reports (which is nearly
> max).  It is as if when some entries expire and are deleted the "storage in
> use" does not go down, eventually leading to the empty folder.
>
> What can be done to diagnose this?  Any kind of cache tracing?
>
> Fx 3.6.12, xp sp3
So we know already that we only count the size of the *entries* in the _CACHE_ files, not their total size (which could be much larger if they once had many entries which have since been evicted):

  https://bugzilla.mozilla.org/show_bug.cgi?id=593198#c14

So that could explain the disparity between the reported cache size and the actual size (block files).  But since we don't count the unused space in the _CACHE_ files, they shouldn't cause the cache to be full.

It's logically possible that the user's cache actually is at the limit, containing only files that are stored in the _CACHE_ files.  But it's statistically very unlikely, since that would mean he's been browsing only files that are smaller than 16K.

al_9x: could you give us the following info?

1) How big are the _CACHE_ files?

2) What is your cache size limit set to currently?  Have you ever manually changed it, and to what size (smaller, bigger; exact #s if you remember them).

3) Cut-and-paste the output of "about:cache" into this bug.

4) Can you verify that you can't actually save new cache entries?  To do this, go to 

    http://people.mozilla.org/~jduell/fail.jpg

And then open "about:cache", click on "list cache entries" in the "Disk Cache Device" section, and search for "fail.jpg".  If you see an entry, it should be in the cache (but check to see if there's a file besides the _CACHE_ files in your Cache directory).

5) Try the same test with a smaller file (which should be stored in the _CACHE_ files), try 

    http://people.mozilla.org/~jduell/cachepain.html

Again, search for 'cachepain' in about:cache to see if its' listed.  If this one is stored, it won't show up as an extra file in the Cache directory).
OS: Linux → Windows XP
Hardware: x86_64 → x86
Version: unspecified → 1.9.2 Branch
Blocks: http_cache
(In reply to comment #1)
> So we know already that we only count the size of the *entries* in the _CACHE_
> files, not their total size (which could be much larger if they once had many
> entries which have since been evicted):
> 
>   https://bugzilla.mozilla.org/show_bug.cgi?id=593198#c14
> 
> So that could explain the disparity between the reported cache size and the
> actual size (block files).  But since we don't count the unused space in the
> _CACHE_ files, they shouldn't cause the cache to be full.
> 
> It's logically possible that the user's cache actually is at the limit,
> containing only files that are stored in the _CACHE_ files.  But it's
> statistically very unlikely, since that would mean he's been browsing only
> files that are smaller than 16K.
> 
> al_9x: could you give us the following info?

You probably want this info at the time of the problem?  I have cleared the cache since the original post and at the moment everything seems to be ok.  The cache is not full, there are many files in the cache folder and the folder size is more or less in sync with "Storage in use," and both of your files were successfully cached.

Number of entries: 	4004
Maximum storage size: 	262144 KiB
Storage in use: 	186845 KiB

Do you want me to wait till the problem develops and post and answer then?
> Do you want me to wait till the problem develops and post and answer then?

Yes.  Without more data it will be hard to track this down.

If/when you see the problem again, if you could keep your copy as your cache as pristine as possible, that would be great.  One easy way to do that would be to create a new profile and continue your daily browsing with that, while you keep the messed-up old profile around just for debugging this.  See

   http://support.mozilla.com/en-US/kb/Managing+profiles

Thanks!
(In reply to comment #2)
> Number of entries:     4004
> Maximum storage size:     262144 KiB
> Storage in use:     186845 KiB

Which Firefox version do you use? Version 3.6.12 is mentioned in the description and it uses 50MB by default. Did you increase the cache size or are you using some beta?
> Did you increase the cache size

yes
Ok, it happened again, I copied the profile, also removed all extensions and reset the prefs (except for the cache size).

> 1) How big are the _CACHE_ files?

_CACHE_001_ - 6.06 MB
_CACHE_003_ - 9.02 MB
_CACHE_003_ - 29.4 MB
_CACHE_MAP_ - 128 KB

> 2) What is your cache size limit set to currently?  Have you ever manually
> changed it, and to what size (smaller, bigger; exact #s if you remember them).

manually changed to 256 MB, long time ago

> 3) Cut-and-paste the output of "about:cache" into this bug.

Disk cache device

Number of entries: 	0
Maximum storage size: 	262144 KiB
Storage in use: 	262144 KiB

> 4) Can you verify that you can't actually save new cache entries?

Nothing is getting cached.
(In reply to comment #6)
> > 4) Can you verify that you can't actually save new cache entries?
> 
> Nothing is getting cached.

What if you point to a large file which should be cached in a separate file?  E.g http://www.mamut.net/dirdalsfioliner/100095.jpg

Could you list the content of your cache-directory for the profile in question? (I.e. list the entire directory where the _CACHE_00x_ files reside.) It looks like your cache only uses bucket-files...?
(In reply to comment #7)
> (In reply to comment #6)
> > > 4) Can you verify that you can't actually save new cache entries?
> > 
> > Nothing is getting cached.
> 
> What if you point to a large file which should be cached in a separate file? 
> E.g http://www.mamut.net/dirdalsfioliner/100095.jpg

Nothing is getting cached.

> Could you list the content of your cache-directory for the profile in question?
> (I.e. list the entire directory where the _CACHE_00x_ files reside.) It looks
> like your cache only uses bucket-files...?

There is nothing in the cache folder aside from the four _CACHE_ files.
Does the cache work normally after FF restart?

Please shutdown FF and attach _CACHE_MAP_ to this bug (it doesn't contain any sensitive data). If you don't mind attach _CACHE_00[1,2,3]_ too (these files contain metadata and data of cached entries). These files are written on shutdown, so the shutdown is necessary before copying the files.
(In reply to comment #9)
> Does the cache work normally after FF restart?
>

no, only clearing cache resets it to normal

> Please shutdown FF and attach _CACHE_MAP_ to this bug (it doesn't contain any
> sensitive data). If you don't mind attach _CACHE_00[1,2,3]_ too (these files
> contain metadata and data of cached entries). These files are written on
> shutdown, so the shutdown is necessary before copying the files.

This is cache from several weeks use of my main profile, I don't know what's in it at this point but I am not going to send it anywhere.

I can build and debug fx if necessary, if someone tells me what to look for.  

Something is probably causing cache entries to be removed without corresponding reduction in the cache in use value.  When it gets to the point when there are 0 entries, it's probably too late to figure it out.  It seems to me the cache code needs some sort of tracing/instrumentation to detect the loss of consistency as it happens.
I can understand that you don't want to share your main-profile cache. :) However, it would be very useful if you would send the CACHE_MAP file directly to either Michal or myself. It does not contain anything sensitive.

Michal: When he clears the cache, do we remove everything? I.e. no bad binary piece of data is left behind which may cause this situation to occur again? There are lots of users who use 3.6.12 without this problem, afaik, and the change to 256M disk-cache size sounds innocent...

Reporter: Are you behind a proxy of some kind? What kind of line do you use (i.e. is it very slow or error-prone)? Is there anything in your browsing-habits you are aware of which may explain this?

(In reply to comment #10)
> I can build and debug fx if necessary, if someone tells me what to look for.  

I don't think we really know what we're looking for, but it will be easy to recognize once we see it. :)
(In reply to comment #11)
> 
> Michal: When he clears the cache, do we remove everything? I.e. no bad binary
> piece of data is left behind which may cause this situation to occur again?

The problem has recurred after deleting the cache folder

> Reporter: Are you behind a proxy of some kind? What kind of line do you use
> (i.e. is it very slow or error-prone)? Is there anything in your
> browsing-habits you are aware of which may explain this?
> 

no proxy, connection is good.  some possibly relevant details:

browser.cache.disk_cache_ssl==true
browser.download.manager.retention==1
"Download Manager Tweak" is installed
"Preserve Download Modification Timestamp" is installed, though I am pretty sure the problem predates it.

I mention the download manager because I noticed that downloads are cached, so perhaps it's related.  By the way, why are they cached?  What's the point of duplicating the data?   It appears that downloads can consume a significant portion of the cache.
@Michal Novotny

Bjarne told me you were looking at the cache map, anything useful?
I took only a quick look at it, but I want to study all records in detail later. What I'm interested in is the status of bitmap in _CACHE_00X_ files. Could you please have a look at first 4096 bytes of all these files with some hexviewer? I expect all bytes in all bitmaps to be 0.
(In reply to comment #14)
> I expect all bytes in all bitmaps to be 0.

yes, all 0
> browser.cache.disk_cache_ssl==true
> browser.download.manager.retention==1
> "Download Manager Tweak" is installed
> "Preserve Download Modification Timestamp" is installed, though I am pretty
> sure the problem predates it.
> 

I was able to exclude the above.

Any ideas?
This problem does not seem to manifest with the default cache size (50 MB).  Please run with 256 MB (262144) for a while, to try to repro this.
Hmm, after quite a long investigation of this bug, I realized that bug #443067 wasn't fixed in 1.9.2 branch. I'm almost sure that this is a dupe, since I couldn't find any other reason after deep inspection of the code.
Status: NEW → RESOLVED
Closed: 12 years ago
Resolution: --- → DUPLICATE
Duplicate of bug: 443067
(In reply to comment #18)
> Hmm, after quite a long investigation of this bug, I realized that bug #443067
> wasn't fixed in 1.9.2 branch. I'm almost sure that this is a dupe, since I
> couldn't find any other reason after deep inspection of the code.
> 

Is that fix going to be backported?
This is not fixed, I am seeing this in 5.0.1, identical symptoms:

browser.cache.disk.smart_size.enabled=false
browser.cache.disk.capacity=256000

Number of entries: 	0
Maximum storage size: 	256000 KiB
Storage in use: 	327680 KiB

the cache folder has 4 _CACHE_ files with a combined size of ~20MB, all the subdirs are empty

to see if this is really bug 443067 I will try to repro it in a new profile, setting cache size to 256 and downloading some source zips from mozilla, first with 3.6 (not fixed) then 5.0.1 (supposedly fixed), however the directions in bug 443067 are rather vague (download some stuff), do you have specific, clear, reliable repro directions?  

please reopen
Bug 443067 seems to have been about making sure that "Storage in use" did not go up during a large download that is not saved to cache.  So far I have been unable to catch it going up in 5.0.  Nevertheless, this bug is real, somehow it got into this state, at least twice, in 5.0.
I found something very strange in _CACHE_MAP_, islands of ascii/unicode strings representing bits of the profile (such as bookmarks jason, some javascript, maybe session jason)

At first I thought the file was corrupted, but after deleting I found the same thing in the recreated one after a day or so.

The source of these string islands, turns out to be clusters of contiguous nsDiskCacheRecords whose mHashNumber is 0, but whose other 12 bytes contain presumably uninitialized garbage which ends up being random profile data from Fx memory. I also found these records in a clean profile with no extension.


Fx should not be storing potentially sensitive profile data from its memory in a totally unexpected location.  This is especially important if one needs to share such a file, which normally would not have any private data.
Bug 673808
Would someone please reopen this bug.
Status: RESOLVED → REOPENED
Resolution: DUPLICATE → ---
Does the large delta:

Maximum storage size: 	256000 KiB
Storage in use: 	327680 KiB

give any clues?  It seems to suggest that a single large download or perhaps a plugin loaded http resource (video) drove the in use value above the max, and was not properly vacated.  Presumably Fx wouldn't let you gradually accumulate such a delta.
Boris and/or Byron,

about this comment:

This patch prevents downloads from being stored in the cache, to the best that we can detect them.
https://bugzilla.mozilla.org/show_bug.cgi?id=55307#c64

Does that mean that some things can escape this ban?  Could that be a component of this bug?
This is probably dupe of #651100. It is already fixed, but the fix is not in Fx5.
(In reply to comment #26)
> This is probably dupe of #651100. It is already fixed, but the fix is not in
> Fx5.

If you understand how this problem would arise without the fix from Bug 651100, then please tell me how to repro it quickly, on demand.
Load following URL to reproduce the bug

jar:http://michal.etc.cz/bug614039/test.jar!/test.html
(In reply to comment #28)
> Load following URL to reproduce the bug
> 
> jar:http://michal.etc.cz/bug614039/test.jar!/test.html

Confirmed.

Please explain what's happening.  I'd like to understand which more normal activities/scenarios (I am not loading jar urls in normal use) and under what conditions, can bring out this bug.
(In reply to comment #29)
> Please explain what's happening.

It is described here:
https://bugzilla.mozilla.org/show_bug.cgi?id=651100#c11


> I'd like to understand which more normal activities/scenarios (I am not
> loading jar urls in normal use) and under what conditions, can bring out
> this bug.

SetCacheAsFile() is called here:
http://mxr.mozilla.org/mozilla-central/search?string=SetCacheAsFile

So this problem _could_ happen e.g. while watching large webm video, when plugin handles a large file etc.
Status: REOPENED → RESOLVED
Closed: 12 years ago → 11 years ago
Resolution: --- → DUPLICATE
Duplicate of bug: 443067
(In reply to comment #30)
> 
> *** This bug has been marked as a duplicate of bug 443067 ***

This is misleading, this bug is still present in 5.0.
You need to log in before you can comment on or make changes to this bug.