1164449 - Startup crash on Moto X (2nd Gen) in android.database.sqlite.SQLiteDatabaseCorruptException: database disk image is malformed (code 11) at android.database.sqlite.SQLiteConnection.nativeExecuteForString(Native Method)

Status: RESOLVED WONTFIX

(Firefox for Android Graveyard :: General, defect)

Description

[[:philipp]]

This bug was filed from the Socorro interface and is 
report bp-d6c7de53-6031-4f80-a67a-d879f2150506.
=============================================================

i was stumbling across this signature after researching a question at sumo, where a user with a motorola x (2nd generation) reported that firefox on android was crashing at startup after updating to firefox 37, continuing in 38 - maybe related to sync:
https://support.mozilla.org/en-US/questions/1061745

this signature would fit the description of the sumo question as it primarily affects motorola x (2nd gen) devices on firefox 37 & 38.

Comment 1

[Aaron Train [:aaronmt]]

This sounds like SQLite corruption on the device. Uninstall, reinstall?

Comment 2

[Matt Brubeck (:mbrubeck)]

I can reproduce this crash.  Aurora crashes 100% of the time when I launch it on my 2nd-gen Moto X.  The crash happens about 10 seconds after launch.

This started happening shortly after I installed Aurora 40 on my new Moto X, but went away when I cleared my profile.  But about a week later it started happening again.

I'm happy to run any diagnostics you want, or share files from my profile (privately).

Comment 3

[Matt Brubeck (:mbrubeck)]

Here's a log with slightly more info:

E/SQLiteLog(11613): (11) database corruption at line 53005 of [9491ba7d73]
E/SQLiteLog(11613): (11) database corruption at line 53044 of [9491ba7d73]
E/SQLiteLog(11613): (11) statement aborts at 15: [SELECT locale FROM android_metadata UNION SELECT NULL ORDER BY locale DESC LIMIT 1]
Failed to open database '/data/data/org.mozilla.fennec_aurora/files/mozilla/2g5c5puw.default/tabs.db'.
android.database.sqlite.SQLiteException: Failed to change locale for db '/data/data/org.mozilla.fennec_aurora/files/mozilla/2g5c5puw.default/tabs.db' to 'en_US'.
       at android.database.sqlite.SQLiteConnection.setLocaleFromConfiguration(SQLiteConnection.java:393)
       at android.database.sqlite.SQLiteConnection.open(SQLiteConnection.java:218)
       at android.database.sqlite.SQLiteConnection.open(SQLiteConnection.java:193)
       at android.database.sqlite.SQLiteConnectionPool.openConnectionLocked(SQLiteConnectionPool.java:463)
       at android.database.sqlite.SQLiteConnectionPool.open(SQLiteConnectionPool.java:185)
       at android.database.sqlite.SQLiteConnectionPool.open(SQLiteConnectionPool.java:177)
       at android.database.sqlite.SQLiteDatabase.openInner(SQLiteDatabase.java:806)
       at android.database.sqlite.SQLiteDatabase.open(SQLiteDatabase.java:791)
       at android.database.sqlite.SQLiteDatabase.openDatabase(SQLiteDatabase.java:694)
       at android.app.ContextImpl.openOrCreateDatabase(ContextImpl.java:1276)
       at android.content.ContextWrapper.openOrCreateDatabase(ContextWrapper.java:267)
       at android.database.sqlite.SQLiteOpenHelper.getDatabaseLocked(SQLiteOpenHelper.java:223)
       at android.database.sqlite.SQLiteOpenHelper.getWritableDatabase(SQLiteOpenHelper.java:163)
       at org.mozilla.gecko.db.DBUtils.ensureDatabaseIsNotLocked(DBUtils.java:87)
       at org.mozilla.gecko.db.PerProfileDatabases.getDatabaseHelperForProfile(PerProfileDatabases.java:80)
       at org.mozilla.gecko.db.AbstractPerProfileDatabaseProvider.getWritableDatabase(AbstractPerProfileDatabaseProvider.java:61)
       at org.mozilla.gecko.db.AbstractTransactionalProvider.delete(AbstractTransactionalProvider.java:185)
       at android.content.ContentProvider$Transport.delete(ContentProvider.java:309)
       at android.content.ContentResolver.delete(ContentResolver.java:1299)
       at org.mozilla.gecko.db.LocalTabsAccessor.persistLocalTabs(LocalTabsAccessor.java:249)
       at org.mozilla.gecko.Tabs$PersistTabsRunnable.run(Tabs.java:91)
       at android.os.Handler.handleCallback(Handler.java:739)
       at android.os.Handler.dispatchMessage(Handler.java:95)
       at android.os.Looper.loop(Looper.java:135)
       at org.mozilla.gecko.util.GeckoBackgroundThread.run(GeckoBackgroundThread.java:43)
Caused by: android.database.sqlite.SQLiteDatabaseCorruptException: database disk image is malformed (code 11)
       at android.database.sqlite.SQLiteConnection.nativeExecuteForString(Native Method)
       at android.database.sqlite.SQLiteConnection.executeForString(SQLiteConnection.java:641)
       at android.database.sqlite.SQLiteConnection.setLocaleFromConfiguration(SQLiteConnection.java:374)
       ... 24 more
D/GeckoDBUtils(11613): Database is locked, trying to kill any zombie processes: /data/data/org.mozilla.fennec_aurora/files/mozilla/2g5c5puw.default/tabs.db

Comment 4

[Matt Brubeck (:mbrubeck)]

Attachment: broken tabs.db

My tabs.db doesn't seem to contain anything too private or embarassing, so here it is.  I can reproduce the error using the `sqlite3` utility on desktop:

$ sqlite3 tabs.db
SQLite version 3.8.6 2014-08-15 11:46:33
Enter ".help" for usage hints.
sqlite> SELECT locale FROM android_metadata UNION SELECT NULL ORDER BY locale DESC LIMIT 1;
Error: database disk image is malformed

Comment 5

[Matt Brubeck (:mbrubeck)]

The `tabs` and `clients` tables are fine; only the `android_metadata` table causes errors.

Comment 6

[Kevin Brosnan [Ex-Mozilla]]

Richard you are our only hope!

Comment 7

[Richard Newman [:rnewman]]

That DB is really corrupt:

sqlite> pragma integrity_check;
integrity_check
----------------------------------------------------------------------
*** in database main ***
Page 3: btreeInitPage() returns error code 11


The cause will be one of these:

https://www.sqlite.org/howtocorrupt.html


Several reports around the web note Android 2.2 or 2.3 and backup/restore. My guess here is a software update causing a backup/restore, and that backup occurring during a transaction. Or Moto's shipped version of sqlite is compiled with some dodgy locking code.

Comment 8

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

Nick - The crashes from crash-stats seem to point to this being a tabs.db issue [1] and not a general DB issue. Makes me think we are doing something to corrupt the DB. Maybe some inter-play with Fennec and Sync processes? In any case, can we get tabs.db to just get blown away and re-build it?


[1] I see these in the stacks I looked at:
       at org.mozilla.gecko.db.LocalTabsAccessor.persistLocalTabs(LocalTabsAccessor.java:249)
       at org.mozilla.gecko.Tabs$PersistTabsRunnable.run(Tabs.java:91)

Comment 9

[Nick Alexander :nalexander [he/him]]

(In reply to Mark Finkle (:mfinkle) from comment #8)
> Nick - The crashes from crash-stats seem to point to this being a tabs.db
> issue [1] and not a general DB issue. Makes me think we are doing something
> to corrupt the DB. Maybe some inter-play with Fennec and Sync processes? In
> any case, can we get tabs.db to just get blown away and re-build it?

Looking at https://crash-stats.mozilla.com/report/list?product=FennecAndroid&signature=android.database.sqlite.SQLiteDatabaseCorruptException%3A+database+disk+image+is+malformed+%28code+11%29+at+android.database.sqlite.SQLiteConnection.nativeExecuteForString%28Native+Method%29#tab-reports, I see:

* more than just Motorola devices;
* multiple versions of Android (17 and 21, at least);
* crashes back to at least Firefox 35.

Reading howtocorrupt.html and a few other sites, the consensus is that this isn't really something that we can address the root cause of.  It's likely an interaction with task killers or Android killing us.  (Although I thought Android killed databases (via ContentProviders) cleanly, but who really knows?)  This is re-inforced by the fact that the issue is in the "android_metadata" table, a table we certainly don't touch ourselves.

That suggests the best thing to do is to work around the problem.  We can catch

android.database.sqlite.SQLiteDatabaseCorruptException: database disk image is malformed (code 11)

and log it (or telemetry it) before destroying the DB entirely.  It's not clear to me how one destroys the DB, given that there could be multiple handles to it, and even multiple file handles.  rnewman, can you give guidance on how to delete said DB?  Is this a thing that we might be better off to add a startup-sentinel for, so that we don't have to think too hard about deleting a DB during execution?

Comment 10

[Richard Newman [:rnewman]]

We already have a startup catch for something similar: see Bug 1065487.

Indeed, you can see that in the stack trace:

       at org.mozilla.gecko.db.DBUtils.ensureDatabaseIsNotLocked(DBUtils.java:87)

so we could quite easily extend that to catch corrupt databases, applying the same remedy -- move the original out of the way and replacing it.

I was hoping to kill that code, but I suppose it still has a purpose!

We very likely want to do something smart here around Sync, like clearing timestamps so we do a full sync again.

Comment 11

[Nick Alexander :nalexander [he/him]]

I'm going to un-track this.  We've rolled Bug 1172077 rolled the contents of tabs.db into browser.db, so if we were seeing this we'd be seeing it with /every/ database.  Since we're not (AFAICT), I'm calling this transient.

Comment 12

[BugBot [:suhaib / :marco/ :calixte]]

Closing because no crashes reported for 12 weeks.