Connection pool closing causing app crash

[zkrige]

java.lang.RuntimeException: An error occurred while executing doInBackground()
at androidx.loader.content.ModernAsyncTask$3.done(ModernAsyncTask.java:164)
at java.util.concurrent.FutureTask.finishCompletion(FutureTask.java:383)
at java.util.concurrent.FutureTask.setException(FutureTask.java:252)
at java.util.concurrent.FutureTask.run(FutureTask.java:271)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1167)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:641)
at java.lang.Thread.run(Thread.java:920)
Caused by: java.lang.IllegalStateException: Cannot perform this operation because the connection pool has been closed.
at net.zetetic.database.sqlcipher.SQLiteConnectionPool.throwIfClosedLocked(SQLiteConnectionPool.java:973)
at net.zetetic.database.sqlcipher.SQLiteConnectionPool.waitForConnection(SQLiteConnectionPool.java:688)
at net.zetetic.database.sqlcipher.SQLiteConnectionPool.acquireConnection(SQLiteConnectionPool.java:359)
at net.zetetic.database.sqlcipher.SQLiteSession.acquireConnection(SQLiteSession.java:929)
at net.zetetic.database.sqlcipher.SQLiteSession.executeForCursorWindow(SQLiteSession.java:869)
at net.zetetic.database.sqlcipher.SQLiteQuery.fillWindow(SQLiteQuery.java:66)
at net.zetetic.database.sqlcipher.SQLiteCursor.fillWindow(SQLiteCursor.java:196)
at net.zetetic.database.sqlcipher.SQLiteCursor.getCount(SQLiteCursor.java:135)
at android.content.ContentResolver.query(ContentResolver.java:1238)
at android.content.ContentResolver.query(ContentResolver.java:1151)

[zkrige]

upon further investigation the seems to happen something like this

get a db instance from SQLiteOpenHelper.getWritableDatabase()
get a 2nd db instance from SQLiteOpenHelper.getWritableDatabase()
run multiple database.rawExecSQL(query) on 2nd instance
do queries, inserts, deletes on first instance

eventually the app crashes with connection pool reference count as 0.

[developernotes]

Hi @zkrige,

Thanks for reaching out. Are you able to reproduce the issue in a standalone application? We'd be happy to review a small public sample if you're able to.

[sjlombardo]

Hi @zkrige - were you able to reproduce this issue in a standalone sample?

[zkrige]

Apologies - I haven't gotten around to building a standalone app

[zkrige]

Sorry I seem to have some confusion. I reported the issue over here -sqlcipher/android-database-sqlcipher#628

I have since moved to using the library in this repo. I was still getting the crash in 4.5.3 of this library

We upgraded to 4.5.4 and will see how new builds behave

[sjlombardo]

Hello @zkrige - have you been able to reproduce this issue under 4.5.4 or 4.5.5?

[zkrige]

Unfortunately still seeing this fairly consistently on 4.5.4. I haven't tested 4.5.5 yet - I will implement and see how it goes

[zkrige]

I'm seeing the same on 4.5.5

[developernotes]

Hi @zkrige,

Thank you for your report. Would it be possible to prepare a standalone sample that showcases the behavior you are experiencing? This would be helpful in diagnosing the issue.

[zkrige]

This definitely seems to be related to doing db work on background threads

ATAL EXCEPTION: pool-33-thread-1
java.lang.IllegalStateException: Cannot perform this operation because the connection pool has been closed.
at net.zetetic.database.sqlcipher.SQLiteConnectionPool.throwIfClosedLocked(SQLiteConnectionPool.java:973)
at net.zetetic.database.sqlcipher.SQLiteConnectionPool.waitForConnection(SQLiteConnectionPool.java:610)
at net.zetetic.database.sqlcipher.SQLiteConnectionPool.acquireConnection(SQLiteConnectionPool.java:359)
at net.zetetic.database.sqlcipher.SQLiteSession.acquireConnection(SQLiteSession.java:929)
at net.zetetic.database.sqlcipher.SQLiteSession.executeForCursorWindow(SQLiteSession.java:869)
at net.zetetic.database.sqlcipher.SQLiteQuery.fillWindow(SQLiteQuery.java:68)
at net.zetetic.database.sqlcipher.SQLiteCursor.fillWindow(SQLiteCursor.java:196)
at net.zetetic.database.sqlcipher.SQLiteCursor.getCount(SQLiteCursor.java:135)
at android.content.ContentResolver.query(ContentResolver.java:1238)
at android.content.ContentResolver.query(ContentResolver.java:1151)
at android.content.ContentResolver.query(ContentResolver.java:1107)
at com.itemRepo.findAllWithCounts(itemRepo.java:71)

 executorService.execute(() -> {
            final List<item> items = itemRepo.findAllWithCounts();

more specifically,

it doesnt happen every time.

it ONLY seems to happen if I have run db upgrades on app startup

private void executeInTry(SQLiteDatabase db, String query) {
try {
if (query.length() > 5) {
db.execSQL(query);
}
} catch (Exception e) {
Timber.w(e, "Error running SQL. [" + query + "]");
}
}
@OverRide
public void onUpgrade(SQLiteDatabase db, int oldVersion, int newVersion) {
for (int upgrade = oldVersion; upgrade <= newVersion; upgrade++) {
if (upgrade == VER_2023_A) {
db.beginTransaction();
try {
db.execSQL("SOME SQL");
db.setTransactionSuccessful();
} finally {
db.endTransaction();
}
executeInTry(db, "CREATE INDEX xxxxxxx");
}
}
}

once the upgrades have been run, and the app doesnt run these statements on startup, then the reference counting seems to work. 

could it be something in execsql that is releasing a reference when it shouldn't?

[zkrige]

not sure if this is related but im seeing a LOT of

The connection pool for database '/data/user/0/app/databases/encrypted.db' has been unable to grant a connection to thread 462 (pool-339-thread-1) with flags 0x1 for 30.594002 seconds. Connections: 0 active, 1 idle, 0 available.

for many different threads

enabling WAL seems to get rid of this, but im not sure if theres other problems that might arise

[zkrige]

I think this is where reference counting goes wonky. for some reason, assigning new SQLiteStatement is decreasing the db reference count

public void rawExecSQL(String sql, Object...bindArgs) throws SQLException {
//mReferenceCount == 2 at this point
acquireReference();
//mReferenceCount == 3 after acquiringreference
try {
SQLiteStatement statement = new SQLiteStatement(this, sql, bindArgs);
//mReferenceCount == 2 after creating new sqlitestatement
try {
statement.executeRaw();
} finally {
statement.close();
}
} finally {
//mReferenceCount == 2
releaseReference();
//mReferenceCount == 1 obviously the count is wrong here, and things go horribly wrong after this
}
}

But I think the reference is being released on another thread

so basically it boils down to reference counting isnt consistent across different threads

[developernotes]

Hi @zkrige, @theBlbDan,

Thank you for providing these details, we would like to investigate the connection pooling issue further. Can you tell us a bit more about your usage of the API so we can better understand what a recreation might entail?

• When you experience the issue, are you always creating multiple SQLiteOpenHelper instances within separate threads?
  • If so, how many instances do you create and how many threads are used?
• Are queries run in all threads prior to this behavior presenting?
• How long does it take before you are unable to acquire the connection from the pool?
• Do you always experience this issue when attempting to execute a query through a ContentResolver?
• Does this only occur when not in WAL mode, or does WAL mode produce this behavior as well?

[zkrige]

thanks for looking at this

• we use a single SQLiteOpenHelper via a singleton
• I'm not able to determine whether or not this is a factor
• because of the inconsistency I cant pin down a time frame
• all queries are done through ContentResolver so im not sure if it happens any other way
• it seems to happen regardless of wether or not WAL is enabled

sorry im not able to provide more info.

In our google play pre-release testing, one device consistently fails but the other 9 devices pass without any issues