Roots of the problem - SQLiteException: not an error


#1

Hi, i’m experiencing mysterious problem - sometimes [SQLiteException: not an error ] is thrown from the SqlitopenHelper. getWritableDatabase()
I googled quite a lot and it seems that people see this error just sometimes. It’s not something that appears constantly. And it disappears if user reinstalls the application. In my case exception is thrown in 100% runs when application goes to prod server. Important thing is that password for crypting db is recieved from there.

I already did quite a lot of things trying to figure out what’s going on:

  1. added the code for cleaning up icudt46l.dat before loadLibs()
  2. renewed sqlcipher to the last version
  3. dug through the code from the repository - just to understand who returns “not an error” message
  4. tried to use simple key for encryption (simple as “test123”) without using the one from server
  5. checked if app has anough rights to write to db path(sick idea, but still had to be check)
  6. tried to call Sqlitedatabase.openOrCreateDatabase(…) instead of getWritableDatabase()
  7. and a lot more stuff… .

I’m quite sure that all necessary things(putting icudt46l.dat to assets, calling loadLibs()) are done correctly. Well, just because it works fine with dev server and the only difference is password.

What I want to understand is under what circumstances native call SQLiteDatabase.dbopen(…) throws this exception? Is it registerLoggingFunc() or sqlite3_open_v2f() or maybe sqlite3_soft_heap_limit().
To be more specific: what call from the dbopen method fails and produces “not an error” message?

I believe that if I knew that i could understand the root of my problem.

The stack trace is
net.sqlcipher.database.SQLiteException: not an error
at net.sqlcipher.database.SQLiteDatabase.dbopen(Native Method)
at net.sqlcipher.database.SQLiteDatabase.(SQLiteDatabase.java:1942)
at net.sqlcipher.database.SQLiteDatabase.openDatabase(SQLiteDatabase.java:875)
at net.sqlcipher.database.SQLiteDatabase.openOrCreateDatabase(SQLiteDatabase.java:907)
at net.sqlcipher.database.SQLiteOpenHelper.getWritableDatabase(SQLiteOpenHelper.java:132)
at net.sqlcipher.database.SQLiteOpenHelper.getWritableDatabase(SQLiteOpenHelper.java:99)

Any hints will be appreciated!


SQLCipher on Android 5.0 X64 emulator crash
#2

Hi @Valeri

While trying to isolate the issue, you should see any native logging routed to logcat if you are able to recreate the error while attached. There are native log statements before each throw in native code. I would be curious if you are seeing the error occur on users where the database is stored on an SD card?


#3

Hi,
thanks for this hint. I will do this. The only problem is that there is plenty of log in logcat. should I filter it by my process? If i do this, i don’t see a lot of logs - only those messages that are mine.

If i should search all the logcat - could you please specify a searchstring to filter log by? just to distinguish the sqlcipher log from the other…


#4

yes, moving db to externale storage was just a part of a test to verify that this problem doesn’t depend on the place where it is stored. We discovered that no, it doesn’t.


#5

This is also reported in https://github.com/sqlcipher/android-database-sqlcipher/issues/139. I recommend that we improve the error reporting, details in my comment in https://github.com/sqlcipher/android-database-sqlcipher/issues/139#issuecomment-106777230.


#6

Hello @Valeri

The tag used in the native code you are referencing is Database, so you can filter on that. We will look into improving error messages where we can.


#7

Ok thanks!

Actually my problem is resolved(well, I hope so - it still needs to go thru QA) after about a week of researches. I’ll describe later today.


#8

Hi,

so my problem is probably resolved. Why “probably”? Because I still can’t explain and prove exactly what caused it.

before the fix loadLibs() call was made in static{} block which was called in UI thread. This occured(it started and finished successfully) before the call to getWritableDatabase(). The getWritableDatabase() was called in other thread(volley thread to be more specific). As I mentioned above this worked fine on our DEV environment, but not on PROD

What I did is (by using intuition, not common sence) I moved the loadLibs() call from the static block to the place executing exactly before getWritableDatabase() and of course in the same volley thread. And voila - it worked!

I’m 100% sure the loadLibs() had enough time to execute even before that fix(saw this in logs). So I’m still trying to answer the question why it worked on DEV env and not working on PROD? The difference between two builds is somewhere on network layer, not on database init layer…

So far it’s probably fixed and will, hopefully, be in production…

thanks for helpful hints above!

sincerely
Valeri


#9

Hello @Valeri

Thank you for sharing your update, we are glad to hear you may have fixed the issue local to your application. Please keep us posted if you see issues in the future.