Performance issues after updating to sqlcipher-android from android-database-sqlcipher

[eygraber]

I updated my app from android-database-sqlcipher 4.5.4 to sqlcipher-android 4.5.5 (I also tried sqlcipher-android 4.5.4 and have the same issue).

When my app starts I make a few network calls and store the responses in the db. After the update to sqlcipher-android the startup performance of my app is absolutely trashed. It takes multiple seconds for my UI to render. I see the following in the logs:

19:16:43.028  I  Database keying operation returned:0
19:16:43.199  W  JNI critical lock held for 167.642ms on Thread[21,tid=30010,Runnable,Thread*=0xb400007b6848e460,peer=0x172c4980,"DefaultDispatcher-worker-3"]
19:16:43.200  I  Database keying operation returned:0
19:16:43.364  W  JNI critical lock held for 162.610ms on Thread[53,tid=30088,Runnable,Thread*=0xb400007b684f15b0,peer=0x13b40738,"DefaultDispatcher-worker-8"]
19:16:43.365  I  Database keying operation returned:0
19:16:43.559  W  JNI critical lock held for 192.855ms on Thread[51,tid=30086,Runnable,Thread*=0xb400007b684ede10,peer=0x130404a8,"DefaultDispatcher-worker-6"]
19:16:43.560  I  Database keying operation returned:0
19:16:43.803  W  JNI critical lock held for 239.118ms on Thread[54,tid=30089,Runnable,Thread*=0xb400007b684fbc90,peer=0x130c1d68,"DefaultDispatcher-worker-9"]
19:16:43.804  I  Database keying operation returned:0
19:16:44.009  W  JNI critical lock held for 203.410ms on Thread[20,tid=30009,Runnable,Thread*=0xb400007b68490030,peer=0x172c44d0,"DefaultDispatcher-worker-2"]
19:16:44.011  I  Database keying operation returned:0
19:16:44.214  W  JNI critical lock held for 202.158ms on Thread[56,tid=30091,Runnable,Thread*=0xb400007b684f6920,peer=0x13c00000,"DefaultDispatcher-worker-11"]
19:16:44.216  I  Database keying operation returned:0
19:16:44.389  W  JNI critical lock held for 171.822ms on Thread[55,tid=30090,Runnable,Thread*=0xb400007b684f84f0,peer=0x13aa7828,"DefaultDispatcher-worker-10"]
+ more after that

This only seems to happen on a cold app open, and happens on both debug and release builds.

I'm trying to profile the build to see what's going on, but Android Studio isn't cooperating at the moment.

[developernotes]

Hi @eygraber,

It appears your application is opening many connections to the same, or different databases. The log statement for keying operation returning 0 is from here. The query that follows triggers key derivation based on your provided password which is slow by design.

Do you have a large number of database files you maintain connections to? If you only have a single database, it would be good to review why the application appears to open the connection repeatedly.

[eygraber]

I only have one database file and access to it is managed by a singleton that opens the connection when it is instantiated. There is a 3rd party layer in between that I'm investigating.

Is the design of sqlcipher-android different than android-database-sqlcipher in this regard? Because there's no performance issue with the same code using android-database-sqlcipher.

[developernotes]

Hi @eygraber,

Yes, sqlcipher-android is different in that it has improved support for concurrent operations when used with WAL mode, this is a big improvement over the android-database-sqlcipher behavior.

sqlcipher-android will use connection pooling when the database is configured to use WAL mode. It can create up to 10 connections that it will provide on-demand. Each SQL operation is processed via a thread local session. Are you executing different SQL operations from different threads at the time the log statements are generated?

[eygraber]

That sounds like it may be it. I'm using WAL and when the app starts it makes a bunch of parallel API calls and writes their responses to the db.

Is there any way to configure the pooling so I can test if that's the issue?

[developernotes]

Hi @eygraber,

The connection pool isn't configurable currently. Can you try disabling WAL mode to see if your performance behavior changes?

[eygraber]

Yes disabling WAL resolves the performance issues. I still see Database keying operation returned:0 logged twice though (instead of the 7-10 times it gets logged with WAL enabled). Is that expected?

[developernotes]

Hi @eygraber,

Do you have a small example where that is occurring with a single connection and WAL mode disabled? The connection pool does distinguish between a primary and non-primary connection based on the connection flags.

[eygraber]

I'm sorry I don't. This is a pretty large app that I can't share. I'll see if I can get it to happen in a repro project.

[amc-apatel]

Hi @developernotes,

I'm also facing this issue after migrating to sqlcipher. Any suggestions to resolve the issue unblock us.

Please check this android example where I've implementated sqlcipher and observing JNI issue.

MyApplication3.zip

Logs from this sample:

2024-04-17 17:51:33.993 9710-9710 SQLiteConnection com.ex.myapplication I Database keying operation returned:0
2024-04-17 17:51:34.283 9710-9710 x.myapplication com.ex.myapplication W JNI critical lock held for 288.246ms on Thread[1,tid=9710,Runnable,Thread*=0x75c1a5f800,peer=0x73217120,"main"]
2024-04-17 17:51:35.323 9710-9710 ViewRootIm...nActivity] com.ex.myapplication I ViewPostIme pointer 0
2024-04-17 17:51:35.402 9710-9710 ViewRootIm...nActivity] com.ex.myapplication I ViewPostIme pointer 1
2024-04-17 17:51:35.426 9710-9710 SQLiteConnection com.ex.myapplication I Database keying operation returned:0
2024-04-17 17:51:35.737 9710-9710 x.myapplication com.ex.myapplication W JNI critical lock held for 311.096ms on Thread[1,tid=9710,Runnable,Thread*=0x75c1a5f800,peer=0x73217120,"main"]
2024-04-17 17:51:35.740 9710-9710 Patient details com.ex.myapplication D Id, name1713356493990Ap

[EpariNigam]

Hey @developernotes after migrating to sqlcipher-android I can clearly see that, it is taking much time to return result.
Same Repo : https://github.com/EpariNigam/SQLCipher

Steps -

• Checkout main branch
• Click insert string
• Kill the app
• Click fetch string and see the time.
• Kill the app
• Now checkout sql_cipher_migration branch
• Click fetch string and see the time. It is almost 2-3 times slower.

[developernotes]

Hi @EpariNigam,

I believe what you are seeing can be attributed to key derivation within your sample. If you adjust your onCreate method to perform a read from sqlite_master (which will trigger key derivation) you will see the query time to fetch users is much better:

override fun onCreate(savedInstanceState: Bundle?) {
        super.onCreate(savedInstanceState)
        tvStatus = findViewById(R.id.tv_status)
        tvData = findViewById(R.id.tv_data)
        db = EncryptedAppDatabase.getInstance(this)
        userDao = db.userDao()
        stringDao = db.stringDao()
        val cursor = db.query("select count(*) from sqlite_master;", null)
        if(cursor.moveToFirst()){
            val rows = cursor.getInt(0);
            Log.i(javaClass.simpleName, String.format("rows:%d", rows))
            cursor.close();
        }
        tvData.movementMethod = ScrollingMovementMethod()
    }

[EpariNigam]

Hey @developernotes Is there no other solution, other than this? Is it like on new library the key derivation is slower compared to old library or was there no key derivation technique used in old library?

[sjlombardo]

@EpariNigam The number of key derivation rounds was increased in SQLCipher 4 by a factor of 4x. This was to increase security against brute force and dictionary attacks. You have a couple options:

1. Use legacy SQLCipher 3 settings, as described by option 2 here. This has security implications as you wouldn't be using the latest settings, but would yield performance similar to SQLCipher 3 on the connection's first use.
2. If your application is using random key material, disable key derivation using a Raw Key. Note that while this would eliminate the time spent with key derivation, it has major security implications. If you aren't using random key material this would be extremely insecure.

Regardless, before doing either of those, you should review the general performance optimization guidelines for your application. If you are adhering to the guidelines and using long running connections the impact of key derivation should be very minimal, since it only happens once per connection.

[sjlombardo]

@EpariNigam disregard my earlier comment. It was directed more at general performance of key derivation, which I now recognize is different than the issue you're facing. We can take a look at this a bit closer, however, I cannot provide a time frame for an update at the moment.