1142694 - QuotaManager default/temporary initialization fails on some profiles

Status: RESOLVED FIXED

(Core :: DOM: Core & HTML, defect)

Description

[(not reading bugmail) Nick Desaulniers [:\n]]

Attachment: test_case.zip

In Nightly 39.0a1 (2015-03-11), and 39.0a1 (2015-03-12), but not release 36.0.1 it looks like the asm.js cache isn't working?  I've attached my test case.  The warning I see in the console is:

Successfully compiled asm.js code (total compilation time 106ms; unable to store in cache due to internal error (consider filing a bug))

Comment 1

[Luke Wagner [:luke]]

Hmm, I can't repro on Nightly on Linux or Windows.  Does the problem repro if you disable e10s on Nightly and/or if you try on a fresh profile?

Comment 2

[(not reading bugmail) Nick Desaulniers [:\n]]

OSX 10.8.5.  Still broken in non-e10s window (damn, everyone's favorite scapegoat!), but cached successfully in other profiles!

Comment 3

[Luke Wagner [:luke]]

Hm, then this may be the same as bug 1128163 comment 13 which looks like a bug in the general storage system (not asm.js caching in particular).  What happens if you move $(PROFILE)/storage/temporary/$(FILE_URL) (where FILE_URL is the file:/// url of your test_cast.zip and should contain an 'asmjs' subdir') to somewhere else (for safekeeping) and try the load again on your original profile?

Comment 4

[(not reading bugmail) Nick Desaulniers [:\n]]

Of all of the `file++++*` dirs in ~/Library/Application Support/Firefox/Profiles/r4z13aww.default/storage/temporary/ , none are for the attached a.out.html!  Maybe that's the problem?  Also nothing related in storage/persistent or storage/permanent.

Comment 5

[Luke Wagner [:luke]]

Ah, forget what I said about the 'asmjs' subdir; if your QuotaManager .metadata file is corrupted, then we won't even get to create an asmjs subdir.  Could you find the 'file+++++*' that matches the subdir containing your a.out.html and experiment with moving it somewhere to see if that allows caching to work?  Another experiment is to copy your a.out.html and a.js to a new subdir and try loading it from there.

Comment 6

[(not reading bugmail) Nick Desaulniers [:\n]]

That's the thing, I _don't_ have a dir corresponding to the file path to my a.out.html.  If I move the test case to another dir, I get the same error and no new additions to ~/Library/Application Support/Firefox/Profiles/r4z13aww.default/storage/temporary/.

Comment 7

[Luke Wagner [:luke]]

Ah, I forgot that they changed this recently; I think by default everything now goes into 'storage/default' (what an appropriate name!).  Do you see anything there?

Comment 8

[(not reading bugmail) Nick Desaulniers [:\n]]

➜  r4z13aww.default  pwd
/Users/Nicholas/Library/Application Support/Firefox/Profiles/r4z13aww.default
➜  r4z13aww.default  tree -L 1 storage
storage
├── permanent
├── persistent
└── temporary

3 directories, 0 files

Comment 9

[Luke Wagner [:luke]]

Interesting!  Ben and Jan, I'm guessing this (comment 8) is a case of failure in MaybeUpgradePersistentStorageDirectory which is then preventing use of default storage?

Comment 10

[Jan Varga [:janv]]

(In reply to Luke Wagner [:luke] from comment #7)
> Ah, I forgot that they changed this recently; I think by default everything
> now goes into 'storage/default' (what an appropriate name!).

asm.js still uses storage/temporary

If there's a problem with MaybeUpgradePersistentStorageDirectory, especially in the origin parser, you should see some warnings in the browser console.
If that's not helpful, try to run it in a debug build and look for assertions/warnings related to dom/quota or dom/asmjscache.

Comment 11

[(not reading bugmail) Nick Desaulniers [:\n]]

I'm not sure if this is related, but I also cannot open IndexDB: http://ie.microsoft.com/testdrive/HTML5/newyearslist/ 

    var dbRequest = window.indexedDB.open(DB_NAME, 1);
    dbRequest.onerror = function () { console.log("Error openning DB"); };

triggers onerror.

This only seems to be affecting this profile, not others.

Comment 12

[Luke Wagner [:luke]]

(In reply to Nick Desaulniers [:\n] from comment #11)
That would be consistent with what I tracked down in another bug (can't find atm) where the failure was in InitTemporaryStorage().  I'm going to add a specific error code/console message for this but in the meantime, do you see anything in the browser console like Jan asked?

Comment 13

[Jan Varga [:janv]]

(In reply to Nick Desaulniers [:\n] from comment #8)
> ➜  r4z13aww.default  pwd
> /Users/Nicholas/Library/Application Support/Firefox/Profiles/r4z13aww.default
> ➜  r4z13aww.default  tree -L 1 storage
> storage
> ├── permanent
> ├── persistent
> └── temporary
> 
> 3 directories, 0 files

Hm, when I create such structure, current nightly correctly renames persistent to default.
Are you sure there are no hidden files in those directories, especially .metadata files ?

Comment 14

[Lawrence Mandel [:lmandel] (use needinfo)]

Vlad tells me this is pretty critical. Tracking across the board.

Comment 15

[Ankit Khare]

A bit of more color - I can repro it and the see specific "Storage initialization failed" message added in https://bugzilla.mozilla.org/show_bug.cgi?id=1155726 for 64 bit windows nightly - 40.0a1 (2015-04-20)

Comment 16

[(not reading bugmail) Nick Desaulniers [:\n]]

Attachment: Debug Build (same profile) log

Comment 17

[(not reading bugmail) Nick Desaulniers [:\n]]

From the logs, I can see:

[73368] WARNING: indexedDB directory shouldn't exist after the upgrade!: file /Users/Nicholas/mozilla/mozilla-central-git/dom/quota/QuotaManager.cpp, line 2035
[73368] WARNING: 'NS_FAILED(rv)', file /Users/Nicholas/mozilla/mozilla-central-git/dom/quota/QuotaManager.cpp, line 4516
[73368] WARNING: 'NS_FAILED(rv)', file /Users/Nicholas/mozilla/mozilla-central-git/dom/quota/QuotaManager.cpp, line 2127
[73368] WARNING: 'NS_FAILED(rv)', file /Users/Nicholas/mozilla/mozilla-central-git/dom/quota/QuotaManager.cpp, line 2193
[73368] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80520014: file /Users/Nicholas/mozilla/mozilla-central-git/dom/quota/QuotaManager.cpp, line 2212
[73368] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80520014: file /Users/Nicholas/mozilla/mozilla-central-git/dom/asmjscache/AsmJSCache.cpp, line 762
[73368] WARNING: indexedDB directory shouldn't exist after the upgrade!: file /Users/Nicholas/mozilla/mozilla-central-git/dom/quota/QuotaManager.cpp, line 2035

Shortly before FF crashed, with a stack trace that looks highly relevant (maybe we failed an assertion).

#01: mozilla::dom::asmjscache::(anonymous namespace)::MainProcessRunnable::CacheMiss()[/Users/Nicholas/mozilla/mozilla-central-git/obj-x86_64-apple-darwin14.1.0/dist/NightlyDebug.app/Contents/MacOS/XUL +0x2da099e]

Comment 18

[Jan Varga [:janv]]

The "indexedDB directory shouldn't exist after the upgrade!" should be harmless. It means that you created "indexedDB" directory in the profile after it has been moved to "storage/persistent". The content of indexedDB directory will be ignored. Maybe some scripts still try to put data into indexedDB. Or maybe you used the same profile with some old firefox release.

However the assertion in AsmJSCache.cpp is interesting, it seems it's not related to storage initialization.

Comment 19

[Luke Wagner [:luke]]

(In reply to Jan Varga [:janv] from comment #18)
> However the assertion in AsmJSCache.cpp is interesting, it seems it's not
> related to storage initialization.

Agreed; this is a pre-existing bug (harmless, I believe, when asserts aren't fatal) triggered by ReadMetadata() failing (presumably triggered by EnsureOriginIsInitialized() failing).

Comment 20

[Luke Wagner [:luke]]

(In reply to Luke Wagner [:luke] from comment #19)
Filed bug 1156600 to fix the assert.  You can either apply that patch or just comment out the assert.

Comment 21

[Sylvestre Ledru [:Sylvestre]]

Luke, could you propose a fix for 38 soon? Beta 7 gtb is today. Thanks

Comment 22

[Luke Wagner [:luke]]

(In reply to Sylvestre Ledru [:sylvestre] from comment #21)
It appears the bug is in IndexedDB and the cause is still unknown (though I think we have two profiles that repro now).  Forwarding to Jan.

Comment 23

[Luke Wagner [:luke]]

(In reply to Luke Wagner [:luke] from comment #22)
Oops, when I wrote "IndexedDB" I should have said "the storage system".

Comment 24

[Sylvestre Ledru [:Sylvestre]]

ok, thanks!

Comment 25

[(not reading bugmail) Nick Desaulniers [:\n]]

(In reply to Jan Varga [:janv] from comment #13)
> Hm, when I create such structure, current nightly correctly renames
> persistent to default.
> Are you sure there are no hidden files in those directories, especially
> .metadata files ?

No hidden files.

➜  r4z13aww.default  ls -a storage
.          ..         permanent  persistent temporary

Jan, what else can I do to help?  Would sending you my profile be helpful?

Comment 26

[Jan Varga [:janv]]

(In reply to Nick Desaulniers [:\n] from comment #25)
> (In reply to Jan Varga [:janv] from comment #13)
> > Hm, when I create such structure, current nightly correctly renames
> > persistent to default.
> > Are you sure there are no hidden files in those directories, especially
> > .metadata files ?
> 
> No hidden files.
> 
> ➜  r4z13aww.default  ls -a storage
> .          ..         permanent  persistent temporary
> 
> Jan, what else can I do to help?  Would sending you my profile be helpful?

Yeah, that would be really helpful.

Comment 27

[(not reading bugmail) Nick Desaulniers [:\n]]

I've sent Jan the contents of my profile/storage directory.  Waiting on his evaluation.

Comment 28

[Sylvestre Ledru [:Sylvestre]]

Unfortunately, too late for 38 but happy to take a fix for 39.

Comment 29

[Luke Wagner [:luke]]

Now the error reproduces for me.  Stepping through QuotaManager::EnsureOriginIsInitialized, we fail in QuotaManager::InitializeOrigin for origin="https://games.mozilla.org", aPersistenceType=default because storage/default/https+++games.mozilla.org contains two subdirs: 'cache' and 'morgue' and Client::TypeFromText('morgue') fails because 'morgue' isn't one of the cases.  Looks like 'morgue' and 'cache' are introduced by dom/cache.

Comment 30

[Luke Wagner [:luke]]

FWIW, there was another origin (https://developer.chrome.com/morgue) with a 'morgue' subdir.  Deleting both (I have a saved copy of my profile dir if anyone needs further debug), everything works.

If it's useful, the 'morgue' subdir contains 4 subdirs named '125', '161', '257', and '54'.  I noticed there is also a 'cache/morgue' dir (which is empty).

Comment 31

[Jan Varga [:janv]]

Ah, so this is actually bug 1165119.

Comment 32

[Ben Kelly [:bkelly, not reviewing]]

Well, bug 1165119 was only introduced on May 7.  So its not the root problem reported in comment 0.

I'm going to do a patch to remove the bad morgue directory today.  Sorry for the issues here.

Comment 33

[Luke Wagner [:luke]]

Ah, I see, so these issues are unrelated.  Probably best to keep looking at Nick's profile, then.

Comment 34

[Luke Wagner [:luke]]

Jan: are there any plans to make storage initialization more robust in the face of these kinds of errors?

Comment 35

[Ben Turner (not reading bugmail, use the needinfo flag!)]

(In reply to Luke Wagner [:luke] from comment #34)
> Jan: are there any plans to make storage initialization more robust in the
> face of these kinds of errors?

We haven't discussed any, no. The problem is that we routinely delete entire directories inside the storage dir, so if a user somehow gets extra files/folders in here then it's hard to know if they're safe to delete.

We definitely need more robust error reporting though so users can at least see what's going wrong and file better bugs...

Comment 36

[Luke Wagner [:luke]]

Ok, I got Nick's profile and was able to reproduce and track this down to two causes:

1. In StorageDirectoryHelper::ProcessOriginDirectories, the MoveTo() call fails when trying to move the dir "$PROFILE/storage/persistent" whose mGroup/mOrigin/mSpec = "indexeddb://fx-devtools".  Removing the dir "$PROFILE/storage/persistent/indexeddb+++fx-devtools" avoids this failure.

2. The call to OriginParser::ParseOrigin fails for the leafName "file++++Users+Nicholas+code+c+++Chocolate-Wolfenstein-3D+wolf3d.html" (presumably the "++" in "c++" in the original filename is being confused with the separator?).  This dir is in storage/temporary and removing it avoids this failure.

With this two removals, everything works and I end up with the expected storage dirs default/permanent/temporary instead of persistent/permanent/temporary.

Comment 37

[(not reading bugmail) Nick Desaulniers [:\n]]

It looks like I had a file url with `c++` in the path, which was asm.js code.  It was stored in storage/temporary/file++++Users+Nicholas+code+c+++Chocolate-Wolfenstein-3D+wolf3d.html where I have a dir:

➜  code  tree -L 1
.
├── assembly
├── c
├── c++
├── crystal
├── java
├── js
├── python
├── r
├── ruby
└── rust

Comment 38

[Liz Henry (:lizzard) (relman/hg->git project)]

Luke or Nick, should release management still be tracking this bug? Are you aiming at a fix here or somewhere else?   We are heading into beta 4 (of 7) at this point for 39.

Comment 39

[Luke Wagner [:luke]]

This seems like a pretty serious regression and one that we should fix since, iiuc, it completely breaks all storage in FF for some users and we've heard, from Epic, that it's breaking people in the wild.

Comment 40

[Liz Henry (:lizzard) (relman/hg->git project)]

Yes that's my impression here too! Thanks Luke.  

Are you taking this on to fix it?  If it shouldn't be one of the 3 of you, let's keep looking for an owner to work on this bug.

Comment 41

[Luke Wagner [:luke]]

This is out of my scope, probably want Jan.

Comment 42

[Liz Henry (:lizzard) (relman/hg->git project)]

jan, sorry to bug you -- can you take this on?

Comment 43

[Jan Varga [:janv]]

Yeah, this is mine.

Comment 44

[Jan Varga [:janv]]

(In reply to Luke Wagner [:luke] from comment #36)
> 1. In StorageDirectoryHelper::ProcessOriginDirectories, the MoveTo() call
> fails when trying to move the dir "$PROFILE/storage/persistent" whose
> mGroup/mOrigin/mSpec = "indexeddb://fx-devtools".  Removing the dir
> "$PROFILE/storage/persistent/indexeddb+++fx-devtools" avoids this failure.

Hm, if the move fails then I guess something else is still using that directory.
I wonder if something in Firefox is accessing that directory directly.

Comment 45

[Jan Varga [:janv]]

(In reply to Luke Wagner [:luke] from comment #36)
> 2. The call to OriginParser::ParseOrigin fails for the leafName
> "file++++Users+Nicholas+code+c+++Chocolate-Wolfenstein-3D+wolf3d.html"
> (presumably the "++" in "c++" in the original filename is being confused
> with the separator?).  This dir is in storage/temporary and removing it
> avoids this failure.

Unfortunately, we won't ever be able to figure out the original file URL.
All these characters :*?"<>|\ are valid on mac, but they are replaced with +
So for example:
file:///Users/varga/:/*/idb.html and
file:///Users/varga/*/:/idb.html both map to
file++++Users+varga+++++idb.html directory in <profile>/storage/temporary

However, the original file URL is not so important since all such origins have their own group.
Fortunately, this problem shouldn't exist for the http schema. We only use the hostname part of URIs and hostnames are not allowed to have these special characters. I actually based the origin parser on this promise. I added file URL support later.
So I think we can add a fallback for file URLs and use unparsed strings for .metadata file creation.

Comment 46

[Jan Varga [:janv]]

Attachment: fix for the c++ thing

This allows a path name component to be an empty string.
So for example:
file++++Users+joe+c+++index.html will be parsed as:
file:///Users/joe/c///index.html

Comment 47

[Liz Henry (:lizzard) (relman/hg->git project)]

Jan or Vlad, is there someone else who can review this?  It would be nice to get into 39, but we are heading into the very end of the beta cycle. So time is short.    For beta 6, this should land by Sunday night. For beta 7, by Wednesday night. Thanks!

Comment 48

[Vladan Djeric (:vladan)]

Liz: did you mean Vladimir Vukicevic? I haven't looked at this code since 2012

Comment 49

[Liz Henry (:lizzard) (relman/hg->git project)]

Sorry, wrong Vlad (from comment 14).

Comment 50

[Ben Turner (not reading bugmail, use the needinfo flag!)]

Comment on attachment 8617551 [details] [diff] [review]
fix for the c++ thing

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

Cool

Comment 51

[Pulsebot]

https://hg.mozilla.org/integration/mozilla-inbound/rev/30d3e9d41e82

Comment 52

[Carsten Book [:Tomcat]]

https://hg.mozilla.org/mozilla-central/rev/30d3e9d41e82

Comment 53

[Luke Wagner [:luke]]

I just tried to verify this fix with the zip of Nick's profile that he sent us earlier and there is still a storage initialization failure.  The two issues reported above seem fixed and the problem now appears to be the half-written 'permanent' dir lying around from the previous failed initialization attempt.  Removing this dir allows the upgrade to succeed and everything works again.

In general, do you think we could have a more robust error handling strategy whereby, if we find garbage in the storage hierarchy, instead of failing completely, we salvage what we can (by copy) into a new storage hierarchy?

Comment 54

[Jan Varga [:janv]]

Luke, what was half-written ?
In general, the upgrade process should be able to recover from a crash, etc.

Comment 55

[Luke Wagner [:luke]]

The profile dir Nick sent contains persistent *and* permanent dirs, and the permanent dir contains some origins also in the persistent dir.

Comment 56

[Jan Varga [:janv]]

Ok, I'll take a look.

Comment 57

[Ben Turner (not reading bugmail, use the needinfo flag!)]

One fix per bug please. Let's make a new one.

Comment 58

[Sylvestre Ledru [:Sylvestre]]

Jan, is it possible to have the uplift request to aurora & beta? Thanks

Comment 59

[Liz Henry (:lizzard) (relman/hg->git project)]

Andrew what do you think? Can you explain the impact of this issue and help us decide if this should uplift to aurora and beta? Sounds like if this has been around since 37. Can this wait to ship with 40?

Comment 60

[Liz Henry (:lizzard) (relman/hg->git project)]

Here is what I can understand of Janv's explanation. If a user tries to open a file:/// url with something like, say, c++ in the url, this breaks initialization permanently. When you restart Firefox and try to access the shared (temporary) storage we try to scan the whole directory structure in that shared storage space and now can't.  The idb database, no DOM cache, no asmjscache all use that space. So no databases can be opened.   Sounds like a bad problem but maybe not super common.

Comment 61

[Liz Henry (:lizzard) (relman/hg->git project)]

On further discussion: I think we should wontfix this for beta. Still would be good to uplift to aurora though.

Comment 62

[Andrew Overholt [:overholt]]

You're correct in comment 60, Liz.  It's a bad situation because of the future ramifications.  That being said, people using IDB or other quotamanager things from file:/// are probably pretty low in numbers.

Comment 63

[Kate Glazko]

Andrew, we are considering letting this patch ride the train. Is that ok with you?

Comment 64

[Andrew Overholt [:overholt]]

(In reply to Kate Glazko from comment #63)
> Andrew, we are considering letting this patch ride the train. Is that ok
> with you?

If we can get an FAQ entry into SUMO, then yes.

Jan, do you agree?

Comment 65

[Jan Varga [:janv]]

(In reply to Andrew Overholt [:overholt] from comment #64)
> (In reply to Kate Glazko from comment #63)
> > Andrew, we are considering letting this patch ride the train. Is that ok
> > with you?
> 
> If we can get an FAQ entry into SUMO, then yes.
> 
> Jan, do you agree?

Yes, I do.

Comment 66

[Sylvestre Ledru [:Sylvestre]]

OK, thanks. Wontfix then.