SQLiteReadOnlyDatabaseException: attempt to write a readonly database (code 1032)

AWT picture AWT · Jan 29, 2016 · Viewed 12.8k times · Source

So in some rare instances, I'm seeing the "attempt to write a readonly database" message, and I can't figure out where the problem lies. I'll start with the stacktrace in my logcat... as you can see from the timestamp I'm checking db.isReadOnly() only 1ms before I attempt the write. (isOpen=true, readOnly=false)

01-29 13:47:49.115: D/AWT(11055): #479.Got writable database (230537815): isOpen: (true) isReadOnly: (false) inTransaction: (false)
01-29 13:47:49.116: D/AWT(11055): #479.in transaction: Got writable database (230537815): isOpen: (true) isReadOnly: (false) inTransaction: (true)
01-29 13:47:49.116: E/SQLiteLog(11055): (1032) statement aborts at 15: [INSERT INTO Events(col1,col2,col3,col4) VALUES (?,?,?,?)] 
01-29 13:47:49.117: E/SQLiteDatabase(11055): Error inserting data="scrubbed"
01-29 13:47:49.117: E/SQLiteDatabase(11055): android.database.sqlite.SQLiteReadOnlyDatabaseException: attempt to write a readonly database (code 1032)
01-29 13:47:49.117: E/SQLiteDatabase(11055):    at android.database.sqlite.SQLiteConnection.nativeExecuteForLastInsertedRowId(Native Method)
01-29 13:47:49.117: E/SQLiteDatabase(11055):    at android.database.sqlite.SQLiteConnection.executeForLastInsertedRowId(SQLiteConnection.java:780)
01-29 13:47:49.117: E/SQLiteDatabase(11055):    at android.database.sqlite.SQLiteSession.executeForLastInsertedRowId(SQLiteSession.java:788)
01-29 13:47:49.117: E/SQLiteDatabase(11055):    at android.database.sqlite.SQLiteStatement.executeInsert(SQLiteStatement.java:86)
01-29 13:47:49.117: E/SQLiteDatabase(11055):    at android.database.sqlite.SQLiteDatabase.insertWithOnConflict(SQLiteDatabase.java:1471)
01-29 13:47:49.117: E/SQLiteDatabase(11055):    at android.database.sqlite.SQLiteDatabase.insert(SQLiteDatabase.java:1341)
01-29 13:47:49.117: E/SQLiteDatabase(11055):    at com.company.DbHelper.insertBatch(EventsDbHelper.java:174)
01-29 13:47:49.117: D/AWT(11055): #479.finalizing transaction: Got writable database (230537815): isOpen: (true) isReadOnly: (false) inTransaction: (true)
01-29 13:47:49.118: W/SQLiteLog(12120): (28) file unlinked while open: /data/user/0/com.company.app/databases/MyDatabase.db

From my source:

public void insertBatch(LinkedList<WriteQueue.DatabaseRecord> writeQueue) throws Exception {
    Log.d("AWT", "EventsDbHelper->insertBatch()");

    if (writeQueue == null) {
        return;
    }

    Iterator<DatabaseRecord> it = writeQueue.iterator();

    SQLiteDatabase db = this.getWritableDatabase();

    Log.d("AWT", String.format("Got writable database (%s): isOpen: (%s) isReadOnly: (%s) inTransaction: (%s)",
            db.hashCode(), db.isOpen(), db.isReadOnly(), db.inTransaction()));

    try {
        db.beginTransaction();

        while (it.hasNext()) {
            DatabaseRecord record = it.next();

            ContentValues initialValues = new ContentValues();
            initialValues.put(col1, val1);
            initialValues.put(col2, val2);
            initialValues.put(col3, val3);
            initialValues.put(col4, val4);

            Log.d("AWT", String.format("in transaction: Got writable database (%s): isOpen: (%s) isReadOnly: (%s) inTransaction: (%s)",
                    db.hashCode(), db.isOpen(), db.isReadOnly(), db.inTransaction()));

            db.insert(DBTBL, null, initialValues);
        }
        Log.d("AWT", String.format("finalizing transaction: Got writable database (%s): isOpen: (%s) isReadOnly: (%s) inTransaction: (%s)",
                db.hashCode(), db.isOpen(), db.isReadOnly(), db.inTransaction()));
        db.setTransactionSuccessful();

    } catch (Exception e) {
        Log.e(TAG, "Error inserting batch record into database.", e);
    } finally {
        try {
            db.endTransaction();
            db.close();
        } catch (Exception e) {
            Log.e(TAG, Global.DB_ERROR, e);
        }
    }
}

So I think that maybe one of two things is happening.

  1. The DB really is being closed/set to "readonly" in that 1ms between the check and the attempted batch insert.
  2. isReadOnly is lying to me and not accurately reporting the state of the database.
  3. Database is being deleted partway through my insert! See the last line of the log above. I turned on strict logging for SQLite and noticed the above. I have a suspicion that a third party library might be dropping all of my databases.

Out of ideas at this point though but I'm willing to try anything suggested.

Answer

AWT picture AWT · Feb 4, 2016

So the root cause of this, at first glance, appears that a third party library. Unless I'm mistaken, Tagit by Mobeix is deleting the database at app startup. I added some detailed SQLite logging, including these policies:

StrictMode.setVmPolicy(new StrictMode.VmPolicy.Builder()
    .detectLeakedSqlLiteObjects()
    .detectLeakedClosableObjects()
    .penaltyLog()
    .penaltyDeath()
    .build());

I noticed in the log that my database is being unlinked after I create and open it. More detailed logging indicates it occurs when the Mobeix library is being initialized. The offending line in question:

01-29 13:47:49.118: W/SQLiteLog(12120): (28) file unlinked while open: /data/user/0/com.company.app/databases/MyDatabase.db

So my database file is unlinked. Weird. The next call to getWritableDatabase() recreates it again and then it's fine until the app is killed and re-launched, at which point it gets deleted and recreated.

I'll update this if I ever figure out exactly what's causing the unlink.