741224 - Can't open tabs.db for writing, browser.db error code = 5, Gecko won't start up

Status: RESOLVED FIXED

(Firefox for Android Graveyard :: General, defect)

Description

[Joe Drew (not getting mail)]

Fennec hung on me for one reason or another, and I killed it. Now Gecko won't start up, and I get the following errors in my adb lolcat:

I/SqliteDatabaseCpp(26427): sqlite returned: error code = 5, msg = statement aborts at 1: [PRAGMA journal_mode=TRUNCATE] , db=/data/data/org.mozilla.fennec/files/mozilla/kfkd3xxm.default/browser.db
E/SQLiteOpenHelper(26427): Couldn't open /data/data/org.mozilla.fennec/files/mozilla/kfkd3xxm.default/tabs.db for writing (will try read-only):
E/SQLiteOpenHelper(26427): android.database.sqlite.SQLiteDatabaseLockedException: error code 5: database is locked
E/SQLiteOpenHelper(26427): 	at android.database.sqlite.SQLiteStatement.native_1x1_string(Native Method)
E/SQLiteOpenHelper(26427): 	at android.database.sqlite.SQLiteStatement.simpleQueryForString(SQLiteStatement.java:161)
E/SQLiteOpenHelper(26427): 	at android.database.DatabaseUtils.stringForQuery(DatabaseUtils.java:735)
E/SQLiteOpenHelper(26427): 	at android.database.DatabaseUtils.stringForQuery(DatabaseUtils.java:723)
E/SQLiteOpenHelper(26427): 	at android.database.sqlite.SQLiteDatabase.setJournalMode(SQLiteDatabase.java:1060)
E/SQLiteOpenHelper(26427): 	at android.database.sqlite.SQLiteDatabase.openDatabase(SQLiteDatabase.java:996)
E/SQLiteOpenHelper(26427): 	at android.database.sqlite.SQLiteDatabase.openOrCreateDatabase(SQLiteDatabase.java:1051)
E/SQLiteOpenHelper(26427): 	at android.app.ContextImpl.openOrCreateDatabase(ContextImpl.java:770)
E/SQLiteOpenHelper(26427): 	at android.content.ContextWrapper.openOrCreateDatabase(ContextWrapper.java:221)
E/SQLiteOpenHelper(26427): 	at android.database.sqlite.SQLiteOpenHelper.getWritableDatabase(SQLiteOpenHelper.java:157)
E/SQLiteOpenHelper(26427): 	at android.database.sqlite.SQLiteOpenHelper.getReadableDatabase(SQLiteOpenHelper.java:231)
E/SQLiteOpenHelper(26427): 	at org.mozilla.fennec.db.TabsProvider.getReadableDatabase(TabsProvider.java:247)
E/SQLiteOpenHelper(26427): 	at org.mozilla.fennec.db.TabsProvider.query(TabsProvider.java:510)
E/SQLiteOpenHelper(26427): 	at android.content.ContentProvider$Transport.query(ContentProvider.java:178)
E/SQLiteOpenHelper(26427): 	at android.content.ContentResolver.query(ContentResolver.java:310)
E/SQLiteOpenHelper(26427): 	at org.mozilla.gecko.TabsAccessor$2.doInBackground(TabsAccessor.java:120)
E/SQLiteOpenHelper(26427): 	at org.mozilla.gecko.TabsAccessor$2.doInBackground(TabsAccessor.java:109)
E/SQLiteOpenHelper(26427): 	at org.mozilla.gecko.GeckoAsyncTask$BackgroundTaskRunnable.run(GeckoAsyncTask.java:61)
E/SQLiteOpenHelper(26427): 	at android.os.Handler.handleCallback(Handler.java:605)
E/SQLiteOpenHelper(26427): 	at android.os.Handler.dispatchMessage(Handler.java:92)
E/SQLiteOpenHelper(26427): 	at android.os.Looper.loop(Looper.java:137)
E/SQLiteOpenHelper(26427): 	at org.mozilla.gecko.GeckoBackgroundThread.run(GeckoBackgroundThread.java:31)
E/GeckoConsole(26427): [JavaScript Error: "Couldn't play common dialog event sound: TypeError: Cc['@mozilla.org/sound;1'] is undefined" {file: "resource://gre/modules/CommonDialog.jsm" line: 213}]
W/SQLiteOpenHelper(26427): Opened /data/data/org.mozilla.fennec/files/mozilla/kfkd3xxm.default/tabs.db in read-only mode

Comment 1

[Joe Drew (not getting mail)]

To be clear: I killed it using the Android "Nightly is not responding, do you want to wait or close it" dialog.

Comment 2

[Richard Newman [:rnewman]]

Moving over to Fennec.

Database corruption can occur whenever you kill a process. In this case Fennec should probably try clearing locks, and in the case of tabs fall back on recreating the DB.

Comment 3

[Sriram Ramasubramanian [:sriram]]

Attachment: WIP

Is this idea right? When I get a DatabaseLocked exception, I delete the database, remove the mapping so that new DatabaseHelper is stored in the map, and then try getting a ReadableDatabase (which will create a new database and re-create tabs and indices (hopefully)).

If this approach is right, I'll extend it to getWritableDatabase() too.

Comment 4

[Richard Newman [:rnewman]]

I think there are two bugs here: firstly it can't open browser.db at all, and secondly it can't open tabs.db for writing. (Note that it successfully opens it for reading, which is the actual call it's trying to make anyway.)

Probably they're related, but not necessarily.

I think the former is a dupe of Bug 722055; consider duping these or reopening that bug and splitting.

(Joe, do you have earlier logs than you posted in Comment 0?)

Sriram, your patch will *probably* fix the latter, but in a very destructive way that wouldn't work for browser.db except in extreme circumstances (which would warrant a resync, too).

And I wouldn't be super keen on landing it without a test. (It should be straightforward to provoke a busted DB: http://www.sqlite.org/howtocorrupt.html)

I encourage you to explore solutions that remove the lock and roll back using the transaction log: e.g.,

http://random.kakaopor.hu/how-to-repair-an-sqlite-database

and also to consider whether there isn't an alternative explanation for what's going on:

http://www.sqlite.org/lockingv3.html

I don't think that this is a bug which would benefit from rushing to a solution without thorough testing. You might find that you blow away user data more frequently than you ought.

Comment 5

[Richard Newman [:rnewman]]

Comment on attachment 612286 [details] [diff] [review]
WIP

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

Giving f- until this has had more analysis.

Comment 6

[Sriram Ramasubramanian [:sriram]]

Searching around the big web, I finally found this guy:

http://developer.android.com/reference/android/database/sqlite/SQLiteDatabase.html#setLockingEnabled%28boolean%29

It states:
"This is pretty expensive, so if you know that your DB will only be used by a single thread then you should set this to false. The default is true."

Since every DB access goes through ContentProvider, I think we are ensuring thread safety there. Aren't we? If so, we should probably turn off setLockingEnabled(). This "might" gives us performance win too.

Comment 7

[Richard Newman [:rnewman]]

(In reply to Sriram Ramasubramanian [:sriram] from comment #6)

> Since every DB access goes through ContentProvider, I think we are ensuring
> thread safety there. Aren't we? If so, we should probably turn off
> setLockingEnabled(). This "might" gives us performance win too.

If you can guarantee it (by never allowing the DB handle and the bridge to escape), then absolutely. Good spot!

Comment 8

[Sriram Ramasubramanian [:sriram]]

Attachment: Patch

Is that all the patch it needs? I've no clue about ContentProviders and the way we handle databases. I just built TabsProvider based on BrowserProvider. I don't know what all will this affect.

Comment 9

[Richard Newman [:rnewman]]

Comment on attachment 612943 [details] [diff] [review]
Patch

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

Have you verified that this avoids the problem?

That is:

* Take a build before this fix
* Force-quit Fennec
* Verify that you can't reopen
* Uninstall
* Repeat with fix
* Verify that you can reopen without error

?

Comment 10

[Erin Lancaster [:elan]]

renoming. I checked with sriram and this issue isn't reproducible enough to test his patches. can we minus until this bug is actionable?

Comment 11

[Mark Finkle (:mfinkle) (use needinfo?)]

Notes:
* Desktop also checks for locked DBs on startup and, if it happens, tells users how to make a new profile. (not that helpful)
* For tabs.db, I'd consider just recreating the DB and let Sync refill the data. Synced tabs do not need to be durable locally.
* For browser.db, we should see if we can pull any data from the DB. If not, we may have no choice but to recreate.

We need to get a busted DB so we can test solutions.

Comment 12

[Lucas Rocha (:lucasr)]

About thread-safety: the important thing for keeping SQLite databases sane in Android is to avoid opening multiple DB connections from different threads. Our content provider solves this problem (as a side effect) because it concentrates all DB accesses into only one DB connection (the SQLiteOpenHelper instance).

So, as long as we don't create separate DB connections to tabs.db or browser.db outside the content provider, it should be (in theory) safe to disable locking. But yes, we need a reliable way to guarantee that this actually fixes the bug here.

Comment 13

[Richard Newman [:rnewman]]

Comment on attachment 612943 [details] [diff] [review]
Patch

Clearing review flag until we get clarity on whether this actually fixes this bug.

Comment 14

[Mark Finkle (:mfinkle) (use needinfo?)]

Let's try to get this fixed. We need to get some logging/data and try to figure out what's happening.

Comment 15

[Mark Finkle (:mfinkle) (use needinfo?)]

See also: bug 741718

Comment 17

[Lucas Rocha (:lucasr)]

FYI: I've just submitted patches to bug 746444 that forces unlocking when the database file is permanently locked after a crash. Given that I couldn't reproduce the bug, I'll land the patch in m-c and see if that reduces the number of "database is locked" issues in the next few days. If the patch does work around the issue, I'll submit another patch to do the same in the tabs database.

Comment 18

[Lucas Rocha (:lucasr)]

Attachment: Force unlock on tabs.db file when database is opened in read-only mode

Comment 19

[Lucas Rocha (:lucasr)]

Attachment: Small fix to the unlock code in BrowserProvider

Comment 20

[Lucas Rocha (:lucasr)]

This patch apply the same unlocking behaviour in tabs.db than in browser.db (see bug 746444).

Comment 21

[Brad Lassey [:blassey] (use needinfo?)]

Comment on attachment 618242 [details] [diff] [review]
Force unlock on tabs.db file when database is opened in read-only mode

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

ensureDatabaseIsNotLocked in TabsProvider.java.in looks identical to BrowserProvider.java.in. Let's share that code somehow

Comment 22

[Lucas Rocha (:lucasr)]

Attachment: (1/2) Move database unlock function to DBUtils

Comment 23

[Lucas Rocha (:lucasr)]

Attachment: (2/2) Force unlock on tabs.db file when database is opened in read-only mode

Comment 24

[Lucas Rocha (:lucasr)]

Didn't care much about the code duplication because the tabs provider is pretty much of copy of browser provider right now. New patches avoid the code duplication.

Comment 25

[Lucas Rocha (:lucasr)]

Pushed:
http://hg.mozilla.org/integration/mozilla-inbound/rev/e2e9bb4029fd
http://hg.mozilla.org/integration/mozilla-inbound/rev/1532311f79da

Comment 26

[Lucas Rocha (:lucasr)]

Comment on attachment 618279 [details] [diff] [review]
(1/2) Move database unlock function to DBUtils

Mobile-only, Fennec beta blocker.

Comment 27

[Lucas Rocha (:lucasr)]

Comment on attachment 618280 [details] [diff] [review]
(2/2) Force unlock on tabs.db file when database is opened in read-only mode

Mobile-only, Fennec beta blocker.

Comment 28

[Lucas Rocha (:lucasr)]

Pushed to aurora:
https://hg.mozilla.org/releases/mozilla-aurora/rev/3fbddad3cfef
https://hg.mozilla.org/releases/mozilla-aurora/rev/cf304a9f3c13

Comment 29

[Ed Morley [:emorley]]

https://hg.mozilla.org/mozilla-central/rev/e2e9bb4029fd
https://hg.mozilla.org/mozilla-central/rev/1532311f79da