1130784 - FAT32 file create limit code is using a bad error number

Status: RESOLVED FIXED

(Core :: Networking: Cache, defect)

Description

[Honza Bambas (:mayhemer)]

In reality, the error NS_ERROR_FILE_NO_DEVICE_SPACE is not the right one.  Correct is NS_ERROR_FILE_ALREADY_EXISTS (converted from Windows error ERROR_CANNOT_MAKE - 82 [1]), which is a surprise to me.

Two ways to fix this:
- use this (illogical) error in the cache code (upliftable)
- fix OpenFile to convert the error based on flags (PR_TRUNCATE)

I don't follow how it is that the cache creates clearly new files in the cache dir.  Probably just rewrites existing ones and that tricked me to believe the code that Michal added actually works.

(Discovered when testing patch for bug 1128339)

[1] http://hg.mozilla.org/mozilla-central/annotate/193c4c5c7ec2/xpcom/io/nsLocalFileWin.cpp#l515

Comment 1

[Honza Bambas (:mayhemer)]

Also, once this has happened to me (the entries dir on the limit):

2015-02-07 22:54:32.283000 UTC - [Cache2 I/O] 6140[2514080]: CacheFileIOManager::OpenNSPRHandle() - Cannot create a new file, we might reached a limit on FAT32. Will evict a single entry and try again. [hash=cf07fccadb44824958bd2db5e4a3d3ec77179e6a]
2015-02-07 22:54:32.283000 UTC - [Cache2 I/O] 6140[2514080]: CacheIndex::GetEntryForEviction()
2015-02-07 22:54:32.283000 UTC - [Cache2 I/O] 6140[2514080]: CacheFileHandles::GetHandle() hash=865d13f2d8edca2b19dce2892c425a89712712bc found handle 1929b680, entry 19127a98
2015-02-07 22:54:32.283000 UTC - [Cache2 I/O] 6140[2514080]: CacheFileHandle::Release() [this=1929b680, refcnt=5]
2015-02-07 22:54:32.283000 UTC - [Cache2 I/O] 6140[2514080]: CacheIndex::GetEntryForEviction() - returning entry from expiration array [hash=865d13f2d8edca2b19dce2892c425a89712712bc, cnt=12914, expTime=0, now=1423349672, frecency=0]
2015-02-07 22:54:32.283000 UTC - [Cache2 I/O] 6140[2514080]: CacheFileIOManager::DoomFileByKeyInternal() [hash=865d13f2d8edca2b19dce2892c425a89712712bc, failIfAlreadyDoomed=1]
2015-02-07 22:54:32.283000 UTC - [Cache2 I/O] 6140[2514080]: CacheFileHandles::GetHandle() hash=865d13f2d8edca2b19dce2892c425a89712712bc found handle 1929b680, entry 19127a98
2015-02-07 22:54:32.283000 UTC - [Cache2 I/O] 6140[2514080]: CacheFileHandle::Log() - entry file [this=1929b680, hash=865d13f2d8edca2b19dce2892c425a89712712bc, isDoomed=0, priority=0, closed=0, invalid=0, fileExists=0, fileSize=0, leafName=865D13F2D8EDCA2B19DCE2892C425A89712712BC, key=:https://www.google.cz/imgevent?ei=BJPWVN_AHY_LaIDYgcAJ&page=2&start=19&ndsp=34&forward=1&iact=sw]
2015-02-07 22:54:32.283000 UTC - [Cache2 I/O] 6140[2514080]: CacheFileIOManager::DoomFileInternal() [handle=1929b680]
2015-02-07 22:54:32.283000 UTC - [Cache2 I/O] 6140[2514080]: CacheFileHandle::Log() - entry file [this=1929b680, hash=865d13f2d8edca2b19dce2892c425a89712712bc, isDoomed=0, priority=0, closed=0, invalid=0, fileExists=0, fileSize=0, leafName=865D13F2D8EDCA2B19DCE2892C425A89712712BC, key=:https://www.google.cz/imgevent?ei=BJPWVN_AHY_LaIDYgcAJ&page=2&start=19&ndsp=34&forward=1&iact=sw]
2015-02-07 22:54:32.283000 UTC - [Cache2 I/O] 6140[2514080]: CacheIndex::RemoveEntry() [hash=865d13f2d8edca2b19dce2892c425a89712712bc]
2015-02-07 22:54:32.283000 UTC - [Cache2 I/O] 6140[2514080]: CacheIndexStats::BeforeChange()
2015-02-07 22:54:32.283000 UTC - [Cache2 I/O] 6140[2514080]: CacheIndexStats::Log() [count=13169, notInitialized=60, removed=195, dirty=360, fresh=362, empty=36, size=259374]
2015-02-07 22:54:32.283000 UTC - [Cache2 I/O] 6140[2514080]: CacheIndexStats::AfterChange()
2015-02-07 22:54:32.283000 UTC - [Cache2 I/O] 6140[2514080]: CacheIndexStats::Log() [count=13169, notInitialized=60, removed=196, dirty=360, fresh=362, empty=35, size=259374]
2015-02-07 22:54:32.283000 UTC - [Cache2 I/O] 6140[2514080]: CacheIndex::RemoveRecordFromFrecencyArray() [record=174ccca0]
2015-02-07 22:54:32.283000 UTC - [Cache2 I/O] 6140[2514080]: CacheIndex::RemoveRecordFromExpirationArray() [record=174ccca0]
2015-02-07 22:54:32.283000 UTC - [Cache2 I/O] 6140[2514080]: RemoveExactEntry [entry=c28b1c0 removed]
2015-02-07 22:54:32.283000 UTC - [Cache2 I/O] 6140[2514080]: CacheEntry::DoomAlreadyRemoved [this=c28b1c0]
2015-02-07 22:54:32.283000 UTC - [Cache2 I/O] 6140[2514080]: CacheFile::Doom() [this=1abfe390, listener=0]
2015-02-07 22:54:32.283000 UTC - [Cache2 I/O] 6140[2514080]: CacheFile::DoomLocked() [this=1abfe390, listener=0]
2015-02-07 22:54:32.283000 UTC - [Cache2 I/O] 6140[2514080]: CacheEntry::BackgroundOp this=c28b1c0 dipatch of 4
2015-02-07 22:54:32.283000 UTC - [Cache2 I/O] 6140[2514080]: CacheEntry UNREGISTER [this=c28b1c0]
2015-02-07 22:54:32.284000 UTC - [Cache2 I/O] 6140[2514080]: CacheStorageService::UnregisterEntry [entry=c28b1c0]
2015-02-07 22:54:32.284000 UTC - [Cache2 I/O] 6140[2514080]: CacheFileHandle::Release() [this=1929b680, refcnt=5]
2015-02-07 22:54:32.288000 UTC - [Cache2 I/O] 6140[2514080]: CacheFileIOManager::OpenNSPRHandle() - Successfully evicted entry with hash 865d13f2d8edca2b19dce2892c425a89712712bc. Failed to create the new file.

The handle says the file already doesn't exist, so there were nothing to delete.  Should we try few times to delete something before we give up?  Like 3 or 5 times?

Comment 2

[Michal Novotny [:michal]]

(In reply to Honza Bambas (:mayhemer) from comment #1)
> The handle says the file already doesn't exist, so there were nothing to
> delete.  Should we try few times to delete something before we give up? 
> Like 3 or 5 times?

In fact, the file doesn't exist yet. We should probably add an argument to CacheIndex::GetEntryForEviction() that would specify whether empty entries should be returned or ignored.

Comment 3

[Michal Novotny [:michal]]

(In reply to Honza Bambas (:mayhemer) from comment #0)
> Two ways to fix this:
> - use this (illogical) error in the cache code (upliftable)
> - fix OpenFile to convert the error based on flags (PR_TRUNCATE)

It would be nice if we got the same error on all platforms, but IIUC the latter option is not upliftable, so we probably need to check for the current error that is returned on Windows.

Comment 4

[Michal Novotny [:michal]]

Attachment: fix

Comment 5

[Honza Bambas (:mayhemer)]

Comment on attachment 8562191 [details] [diff] [review]
fix

Review of attachment 8562191 [details] [diff] [review]:
-----------------------------------------------------------------

r=honzab

::: netwerk/cache2/CacheFileIOManager.cpp
@@ +3639,5 @@
>    if (aCreate) {
>      rv = aHandle->mFile->OpenNSPRFileDesc(
>             PR_RDWR | PR_CREATE_FILE | PR_TRUNCATE, 0600, &aHandle->mFD);
> +    if (rv == NS_ERROR_FILE_ALREADY_EXISTS ||
> +        rv == NS_ERROR_FILE_NO_DEVICE_SPACE) {

maybe add a comment why NS_ERROR_FILE_ALREADY_EXISTS is needed here (it's not that much expected)

Comment 6

[Michal Novotny [:michal]]

Attachment: patch v2 - added comment

https://hg.mozilla.org/integration/mozilla-inbound/rev/614eb0ebe557

Comment 7

[Michal Novotny [:michal]]

Comment on attachment 8563326 [details] [diff] [review]
patch v2 - added comment

Approval Request Comment
[Feature/regressing bug #]: the bug is present in cache v2 from the beginning and the fix in bug 1120945 works only on systems using nsLocalFileUnix
[User impact if declined]: new entries are not cached on FAT32 when the entry directory is full on Windows
[Describe test coverage new/current, TreeHerder]: tested manually
[Risks and why]: low
[String/UUID change made/needed]: none

Comment 8

[Ryan VanderMeulen [:RyanVM]]

https://hg.mozilla.org/mozilla-central/rev/614eb0ebe557

Comment 9

[Sylvestre Ledru [:Sylvestre]]

Comment on attachment 8563326 [details] [diff] [review]
patch v2 - added comment

I am not sure that it is a big deal with the user entry directory is full that it won't be cached. I might be wrong but it seems to be a corner case and it can ride the train with 37 as we are late in the 36 cycle.

Comment 10

[Ryan VanderMeulen [:RyanVM]]

https://hg.mozilla.org/releases/mozilla-aurora/rev/d0d290f35a84

Comment 11

[Michal Novotny [:michal]]

(In reply to Sylvestre Ledru [:sylvestre] from comment #9)
> I am not sure that it is a big deal with the user entry directory is full
> that it won't be cached. I might be wrong but it seems to be a corner case
> and it can ride the train with 37 as we are late in the 36 cycle.

I don't think this is a corner case. We guess (but we don't have numbers) that majority of Windows users use NTFS, but the users with FAT/FAT32 will almost certainly reach the directory limit.

Comment 12

[Jason Duell]

Comment on attachment 8563326 [details] [diff] [review]
patch v2 - added comment

Sylvestre,

Without this patch our uplift of bug 1120945 to beta will be broken, i.e. FAT32 users will wind up having their HTTP cache no longer cache entries once it's full (i.e. after they've browsed for a few days with the same profile--not a corner case).  So I'd urge that we take this patch on beta

Comment 13

[Sylvestre Ledru [:Sylvestre]]

(In reply to Michal Novotny (:michal) from comment #11)
> (In reply to Sylvestre Ledru [:sylvestre] from comment #9)
> > I am not sure that it is a big deal with the user entry directory is full
> > that it won't be cached. I might be wrong but it seems to be a corner case
> > and it can ride the train with 37 as we are late in the 36 cycle.
> 
> I don't think this is a corner case. We guess (but we don't have numbers)
> that majority of Windows users use NTFS, but the users with FAT/FAT32 will
> almost certainly reach the directory limit.
I am sorry but in your message, you said 
"new entries are not cached on FAT32 when the entry directory is full on Windows"
Not caching is a pain but not a critical issue and, it seems that this bug and bug 1120945 have been there for a while.

FYI, we are not going to make any more beta, just a RC. So, can you explain what kind of manual testing you have done? Why we don't have tests?

Comment 14

[Patrick McManus [:mcmanus]]

(In reply to Sylvestre Ledru [:sylvestre] from comment #13)

> 
> FYI, we are not going to make any more beta, just a RC.

based on that I would agree that it should go to gecko-36

Comment 15

[Patrick McManus [:mcmanus]]

(In reply to Patrick McManus [:mcmanus] from comment #14)
> 
> based on that I would agree that it should go to gecko-36

I of course mean agree Sylvestre that it should not go to gecko-36 based on there only being an RC left on that channel.

I'm sorry for the confusion.

Comment 16

[Michal Novotny [:michal]]

(In reply to Sylvestre Ledru [:sylvestre] from comment #13)
> I am sorry but in your message, you said 
> "new entries are not cached on FAT32 when the entry directory is full on
> Windows"

That's correct. The cache will stop caching further entries once it contains 13106 files.


> Not caching is a pain but not a critical issue and, it seems that this bug
> and bug 1120945 have been there for a while.
> 
> FYI, we are not going to make any more beta, just a RC. So, can you explain
> what kind of manual testing you have done? Why we don't have tests?

I've tested it manually. If it is possible to ensure that the profile is placed on FAT32 then I can create xpcshell test.

Comment 17

[Sylvestre Ledru [:Sylvestre]]

(In reply to Michal Novotny (:michal) from comment #16)
> That's correct. The cache will stop caching further entries once it contains
> 13106 files.
Ok, so, Firefox will become slower but will remain functional?

Is it a new regression?

Comment 18

[Michal Novotny [:michal]]

(In reply to Sylvestre Ledru [:sylvestre] from comment #17)
> (In reply to Michal Novotny (:michal) from comment #16)
> > That's correct. The cache will stop caching further entries once it contains
> > 13106 files.
> Ok, so, Firefox will become slower but will remain functional?

The browser should work normally when it's not expected that the resource will be fetched only from the cache. People can experience problems navigating back/forward in history if the page was a result of document.write() or post request, but this can IMO happen (to a lesser extent) even with this patch or on unaffected filesystems.

> Is it a new regression?

The bug is the new cache from the beginning.

Comment 19

[Sylvestre Ledru [:Sylvestre]]

(In reply to Michal Novotny (:michal) from comment #18)
> > Is it a new regression?
> 
> The bug is the new cache from the beginning.
So, that feature landed a while ago, right?

Comment 20

[Michal Novotny [:michal]]

(In reply to Sylvestre Ledru [:sylvestre] from comment #19)
> So, that feature landed a while ago, right?

IIRC it is enabled since Firefox 32.

Comment 21

[Sylvestre Ledru [:Sylvestre]]

(In reply to Michal Novotny (:michal) from comment #20)
> (In reply to Sylvestre Ledru [:sylvestre] from comment #19)
> > So, that feature landed a while ago, right?
> 
> IIRC it is enabled since Firefox 32.
OK, so, it can wait 5 more weeks I think.
I am sorry to be a pain about that but 36 has not been an easy release and I am trying to limit the last patches to only critical issues.