Possible to get specific error details from Android SQLiteConstraintException?

Question

I'm getting the following error for certain data, and concept is clear enough:

android.database.sqlite.SQLiteConstraintException: FOREIGN KEY constraint failed (code 787)

However, that doesn't help me find which specific record has the invalid FK. Rather than thrash my code and try to isolate every insert with a new transaction, is there any way to turn on (or extract) logging with helpful details such as the table in question or even the FK value that is causing trouble?

Also, I'm using SqlBrite, and have turned debug logging on (that just logs the operations, I still don't get more info on the error)

Update: Here's all of the logcat above my own code; essentially the exception is caught when trying to close a transaction (BriteDatabase.Transaction) previously opened (the BriteDatabase.Transaction object is a new addition; I just migrated from SqlBrite 0.1.0 to 0.4.1).

android.database.sqlite.SQLiteConstraintException: FOREIGN KEY constraint failed (code 787)
    at android.database.sqlite.SQLiteConnection.nativeExecute(Native Method)
    at android.database.sqlite.SQLiteConnection.execute(SQLiteConnection.java:555)
    at android.database.sqlite.SQLiteSession.endTransactionUnchecked(SQLiteSession.java:437)
    at android.database.sqlite.SQLiteSession.endTransaction(SQLiteSession.java:401)
    at android.database.sqlite.SQLiteDatabase.endTransaction(SQLiteDatabase.java:522)
    at com.squareup.sqlbrite.BriteDatabase$1.end(BriteDatabase.java:85)

Persaud

I updated to add all of the logcat above my own internal code. – Persaud

Probably need the sql, too. You're might be trying to deleted a record from one table that has a reference in another table, (or trying to delete a record by referring to it with a null Id?) – Anacoluthia

Hi Al - I'm not trying to solve the problem here, I'm trying to find better tools to solve this and future problems. I'm certain that one of the records has a foreign key to a row that exists on the server but doesn't exist in the local DB (this happens while creating new rows with data just retrieved from the server). I already solved one such problem by making a local table column a text field rather than a reference. I'm just confused as to why the code that has access to the data I need (which table, column, and data value are causing a problem) doesn't bother to report it. – Persaud

Answer 1

Solution 1:

You can use the adb shell dumpsys dbinfo -v command to see some info about databases.

In my case, I have created a small example that inserts the same record twice forcing a SQLiteConstraintException:

MyDB db = new MyDB(this);

// Insert the same record twice to force a SQLiteConstraintException
db.insertIntoMyTable("1","MyName");
db.insertIntoMyTable("1","MyName");

This is the output of the adb shell dumpsys dbinfo -v command in my Nexus 4 (I am not sure, but I think that the output info can differ between devices):

Connection pool for /data/data/com.your.package.name/databases/MyDB:
Open: true
Max connections: 1
Available primary connection:
Connection #0:
  connectionPtr: 0xffffffffb883aaf0
  isPrimaryConnection: true
  onlyAllowReadOnlyOperations: false
  Most recently executed operations:
    0: [2015-11-13 17:59:16.227] executeForLastInsertedRowId took 1ms - failed, sql="INSERT INTO MyTable(name,_id) VALUES (?,?)", bindArgs=["MyName", "1"], exception="UNIQUE constraint failed: MyTable._id (code 1555)"
    1: [2015-11-13 17:59:16.227] prepare took 0ms - succeeded, sql="INSERT INTO MyTable(name,_id) VALUES (?,?)"
    2: [2015-11-13 17:59:16.209] executeForLastInsertedRowId took 18ms - succeeded, sql="INSERT INTO MyTable(name,_id) VALUES (?,?)", bindArgs=["MyName", "1"]
    3: [2015-11-13 17:59:16.209] prepare took 0ms - succeeded, sql="INSERT INTO MyTable(name,_id) VALUES (?,?)"
    4: [2015-11-13 17:59:16.208] executeForLong took 1ms - succeeded, sql="PRAGMA user_version;"
    5: [2015-11-13 17:59:16.208] prepare took 0ms - succeeded, sql="PRAGMA user_version;"
    6: [2015-11-13 17:59:16.208] executeForString took 0ms - succeeded, sql="SELECT locale FROM android_metadata UNION SELECT NULL ORDER BY locale DESC LIMIT 1"
    7: [2015-11-13 17:59:16.207] execute took 1ms - succeeded, sql="CREATE TABLE IF NOT EXISTS android_metadata (locale TEXT)"
    8: [2015-11-13 17:59:16.207] executeForLong took 0ms - succeeded, sql="PRAGMA wal_autocheckpoint=100"
    9: [2015-11-13 17:59:16.207] executeForLong took 0ms - succeeded, sql="PRAGMA wal_autocheckpoint"
    10: [2015-11-13 17:59:16.207] executeForLong took 0ms - succeeded, sql="PRAGMA journal_size_limit=524288"
    11: [2015-11-13 17:59:16.207] executeForLong took 0ms - succeeded, sql="PRAGMA journal_size_limit"
    12: [2015-11-13 17:59:16.206] executeForString took 0ms - succeeded, sql="PRAGMA synchronous"
    13: [2015-11-13 17:59:16.206] executeForString took 0ms - succeeded, sql="PRAGMA journal_mode=PERSIST"
    14: [2015-11-13 17:59:16.205] executeForString took 1ms - succeeded, sql="PRAGMA journal_mode"
    15: [2015-11-13 17:59:16.204] executeForLong took 0ms - succeeded, sql="PRAGMA foreign_keys"
    16: [2015-11-13 17:59:16.204] executeForLong took 0ms - succeeded, sql="PRAGMA page_size"
  Prepared statement cache:
    0: statementPtr=0xffffffffb8839558, numParameters=0, type=1, readOnly=true, sql="SELECT locale FROM android_metadata UNION SELECT NULL ORDER BY locale DESC LIMIT 1"
Available non-primary connections:
<none>
Acquired connections:
<none>
Connection waiters:
<none>

Analyzing the output, in the Most recently executed operations: I get the following info (one record successfully inserted, and another failed):

0: [2015-11-13 17:59:16.227] executeForLastInsertedRowId took 1ms - failed, sql="INSERT INTO MyTable(name,_id) VALUES (?,?)", bindArgs=["MyName", "1"], exception="UNIQUE constraint failed: MyTable._id (code 1555)"
2: [2015-11-13 17:59:16.209] executeForLastInsertedRowId took 18ms - succeeded, sql="INSERT INTO MyTable(name,_id) VALUES (?,?)", bindArgs=["MyName", "1"]

Solution 2:

This solution is a bit tricky, but you can use the android.database.sqlite.SQLiteDebug class to get similar info via Java code.

If you take a look at this you will see that this class is marked as @hide which means that the SQLiteDebug class is excluded from the API docs, but it can still be accessed via reflection.

So, to print the debug info for the SQLite databases, you can use the following code:

// The messages will be printed as Log.ERROR using the tag "DB"
Printer p = new LogPrinter(Log.ERROR, "DB");
// We will invoke the "dump" method of the "android.database.sqlite.SQLiteDebug" class
// We eill use the "-v" parameter because we want the output to be verbose
Class<?> c = Class.forName("android.database.sqlite.SQLiteDebug");
Method method = c.getMethod("dump", new Class[]{Printer.class, String[].class});
method.invoke(null, p, new String[]{"-v"});

A simple example to illustrate the solution:

MyDB db = new MyDB(this);

// Insert the same record twice to force a SQLiteConstraintException
db.insertIntoMyTable("1","MyName");
db.insertIntoMyTable("1","MyName");

try {
    Printer p = new LogPrinter(Log.ERROR, "DB");
    Class<?> c = Class.forName("android.database.sqlite.SQLiteDebug");
    Method method = c.getMethod("dump", new Class[]{Printer.class, String[].class});
    method.invoke(null, p, new String[]{"-v"});
}
catch (Exception e) {
    Log.e("MyTag", e.getMessage());
}

In this case I use a LogPrinter to dump the debug info to logcat, but you can use your own Printer implementation.

In my Nexus 4, the logcat looks like this (I am not sure, but I think that the output info can differ between devices):

E/SQLiteLog(22296): (1555) abort at 10 in [INSERT INTO MyTable(name,_id) VALUES (?,?)]: UNIQUE constraint failed: MyTable._id
E/SQLiteDatabase(22296): Error inserting name=MyName _id=1
E/SQLiteDatabase(22296): android.database.sqlite.SQLiteConstraintException: UNIQUE constraint failed: MyTable._id (code 1555)
E/SQLiteDatabase(22296):    at android.database.sqlite.SQLiteConnection.nativeExecuteForLastInsertedRowId(Native Method)
E/SQLiteDatabase(22296):    at android.database.sqlite.SQLiteConnection.executeForLastInsertedRowId(SQLiteConnection.java:782)
E/SQLiteDatabase(22296):    at android.database.sqlite.SQLiteSession.executeForLastInsertedRowId(SQLiteSession.java:788)
E/SQLiteDatabase(22296):    at android.database.sqlite.SQLiteStatement.executeInsert(SQLiteStatement.java:86)
E/SQLiteDatabase(22296):    at android.database.sqlite.SQLiteDatabase.insertWithOnConflict(SQLiteDatabase.java:1471)
E/SQLiteDatabase(22296):    at android.database.sqlite.SQLiteDatabase.insert(SQLiteDatabase.java:1341)
E/SQLiteDatabase(22296):    at com.example.antonio.prueba3.MyDB.insertIntoMyTable(MyDB.java:32)
E/SQLiteDatabase(22296):    at com.example.antonio.prueba3.MainActivity.onCreate(MainActivity.java:24)
E/SQLiteDatabase(22296):    at android.app.Activity.performCreate(Activity.java:5990)
E/SQLiteDatabase(22296):    at android.app.Instrumentation.callActivityOnCreate(Instrumentation.java:1106)
E/SQLiteDatabase(22296):    at android.app.ActivityThread.performLaunchActivity(ActivityThread.java:2278)
E/SQLiteDatabase(22296):    at android.app.ActivityThread.handleLaunchActivity(ActivityThread.java:2387)
E/SQLiteDatabase(22296):    at android.app.ActivityThread.access$800(ActivityThread.java:151)
E/SQLiteDatabase(22296):    at android.app.ActivityThread$H.handleMessage(ActivityThread.java:1303)
E/SQLiteDatabase(22296):    at android.os.Handler.dispatchMessage(Handler.java:102)
E/SQLiteDatabase(22296):    at android.os.Looper.loop(Looper.java:135)
E/SQLiteDatabase(22296):    at android.app.ActivityThread.main(ActivityThread.java:5254)
E/SQLiteDatabase(22296):    at java.lang.reflect.Method.invoke(Native Method)
E/SQLiteDatabase(22296):    at java.lang.reflect.Method.invoke(Method.java:372)
E/SQLiteDatabase(22296):    at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:903)
E/SQLiteDatabase(22296):    at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:698)
E/DB      (22296): Connection pool for /data/data/com.example.antonio.prueba3/databases/MyDB:
E/DB      (22296):   Open: true
E/DB      (22296):   Max connections: 1
E/DB      (22296):   Available primary connection:
E/DB      (22296):     Connection #0:
E/DB      (22296):       connectionPtr: 0xffffffffb883aaf0
E/DB      (22296):       isPrimaryConnection: true
E/DB      (22296):       onlyAllowReadOnlyOperations: false
E/DB      (22296):       Most recently executed operations:
E/DB      (22296):         0: [2015-11-13 17:59:16.227] executeForLastInsertedRowId took 1ms - failed, sql="INSERT INTO MyTable(name,_id) VALUES (?,?)", bindArgs=["MyName", "1"], exception="UNIQUE constraint failed: MyTable._id (code 1555)"
E/DB      (22296):         1: [2015-11-13 17:59:16.227] prepare took 0ms - succeeded, sql="INSERT INTO MyTable(name,_id) VALUES (?,?)"
E/DB      (22296):         2: [2015-11-13 17:59:16.209] executeForLastInsertedRowId took 18ms - succeeded, sql="INSERT INTO MyTable(name,_id) VALUES (?,?)", bindArgs=["MyName", "1"]
E/DB      (22296):         3: [2015-11-13 17:59:16.209] prepare took 0ms - succeeded, sql="INSERT INTO MyTable(name,_id) VALUES (?,?)"
E/DB      (22296):         4: [2015-11-13 17:59:16.208] executeForLong took 1ms - succeeded, sql="PRAGMA user_version;"
E/DB      (22296):         5: [2015-11-13 17:59:16.208] prepare took 0ms - succeeded, sql="PRAGMA user_version;"
E/DB      (22296):         6: [2015-11-13 17:59:16.208] executeForString took 0ms - succeeded, sql="SELECT locale FROM android_metadata UNION SELECT NULL ORDER BY locale DESC LIMIT 1"
E/DB      (22296):         7: [2015-11-13 17:59:16.207] execute took 1ms - succeeded, sql="CREATE TABLE IF NOT EXISTS android_metadata (locale TEXT)"
E/DB      (22296):         8: [2015-11-13 17:59:16.207] executeForLong took 0ms - succeeded, sql="PRAGMA wal_autocheckpoint=100"
E/DB      (22296):         9: [2015-11-13 17:59:16.207] executeForLong took 0ms - succeeded, sql="PRAGMA wal_autocheckpoint"
E/DB      (22296):         10: [2015-11-13 17:59:16.207] executeForLong took 0ms - succeeded, sql="PRAGMA journal_size_limit=524288"
E/DB      (22296):         11: [2015-11-13 17:59:16.207] executeForLong took 0ms - succeeded, sql="PRAGMA journal_size_limit"
E/DB      (22296):         12: [2015-11-13 17:59:16.206] executeForString took 0ms - succeeded, sql="PRAGMA synchronous"
E/DB      (22296):         13: [2015-11-13 17:59:16.206] executeForString took 0ms - succeeded, sql="PRAGMA journal_mode=PERSIST"
E/DB      (22296):         14: [2015-11-13 17:59:16.205] executeForString took 1ms - succeeded, sql="PRAGMA journal_mode"
E/DB      (22296):         15: [2015-11-13 17:59:16.204] executeForLong took 0ms - succeeded, sql="PRAGMA foreign_keys"
E/DB      (22296):         16: [2015-11-13 17:59:16.204] executeForLong took 0ms - succeeded, sql="PRAGMA page_size"
E/DB      (22296):       Prepared statement cache:
E/DB      (22296):         0: statementPtr=0xffffffffb8839558, numParameters=0, type=1, readOnly=true, sql="SELECT locale FROM android_metadata UNION SELECT NULL ORDER BY locale DESC LIMIT 1"
E/DB      (22296):   Available non-primary connections:
E/DB      (22296):     <none>
E/DB      (22296):   Acquired connections:
E/DB      (22296):     <none>
E/DB      (22296):   Connection waiters:
E/DB      (22296):     <none>

Analyzing the output, I get a SQLiteConstraintException:

E/SQLiteDatabase(22296): android.database.sqlite.SQLiteConstraintException: UNIQUE constraint failed: MyTable._id (code 1555)

And in the Most recently executed operations: I get the following info (one record successfully inserted, and another failed):

E/DB      (22296):         0: [2015-11-13 17:59:16.227] executeForLastInsertedRowId took 1ms - failed, sql="INSERT INTO MyTable(name,_id) VALUES (?,?)", bindArgs=["MyName", "1"], exception="UNIQUE constraint failed: MyTable._id (code 1555)"
E/DB      (22296):         2: [2015-11-13 17:59:16.209] executeForLastInsertedRowId took 18ms - succeeded, sql="INSERT INTO MyTable(name,_id) VALUES (?,?)", bindArgs=["MyName", "1"]

Hope it helps.

Oenomel

It doesn't work exactly the same for me, as I have transactions and get the error on the commit, however this is a good tool to use when I haven't enabled logging on the DB calls. I still have to slice up the inserts into separate transactions to track down the problem, but I'll award the bounty since this is a useful addition to my toolbox. – Persaud

I came back and implemented a logger that extracts info from the dump using your method 2. With some creative regex action I can scrape the line in question with the query params (without sensitive data I can't track in production), which happens to be the line after it says failure, since I use transactions. So long as I isolate potentially troublesome commands 1-per-transaction this looks like it could be useful in production. – Persaud

Glad to hear that the solution is helping in producton environments, but take into account when using your regex that the output can differ between devices (at least the output differs on the two different devices I have tested it). Thank you for the follow up. – Oenomel

Answer 2

Simply you can take out that SQLite file from your device and then load it in a SQLite browser app. So, you can now attempt to execute the same transaction and see what is going on.

SQLite Browsers:

• SQLite Browser
• SQLite Manager
• SQLite Studio

Hollingshead

Hi, thanks - I do use SQLite Studio and frequently pull the DB locally to inspect and interact. However, the SQL in question could be hundreds of lines - I'm inspecting production data to figure out what bit of it is problematic. By the time I've broken up all the commits into separate transactions to isolate the problem line, I've already done most of the work that I was trying to save, and a few queries on the local copy of the DB do indeed show me which FK refers to a missing row. – Persaud