java.util.concurrent.TimeoutException: net.sqlcipher.database.SQLiteCompiledSql.finalize() timed out after 10 seconds

Expected Behavior

App doesn't crash

Actual Behavior

App crashes due to SQLiteCipher on Android API 24-25

Steps to Reproduce

App uses Room + SQLCipher.
WAL is enabled.

The only synthetic case how I can emulate crash is accessing SQLiteCompiledSql(Use API 24-25 Android emulator):

Launch thread A
Launch thread B
Block B, In A create SQLiteCompiledSql object, set nStatement so that finalize can run releaseSqlStatement, block A, unblock B
In B launch start a long transaction, unblock A, do memory extensive work to cause GC
Wait

Android test Kotlin code(if required I can convert to Java):

  @Test
    fun emulateCrash() = coroutineRule.runBlocking {
        dbRule.useWithProject {
            val latch1 = CountDownLatch(1)
            val latch2 = CountDownLatch(1)

            launch (Dispatchers.IO) {
                SQLiteProxy(db.openHelper.writableDatabase as SQLiteDatabase, "SELECT 1 FROM Album").setupStub()
                latch2.countDown()
                latch1.await()
            }

            latch2.await()
            db.withTransaction {
                latch1.countDown()
                while (true) {
                    // no matter what  - just pollute memory to cause GC
                    val albumEntity = newAlbum(
                        projectEntity = projectEntity,
                        companyEntity = companyEntity
                    )
                }
            }
        }
    }

package net.sqlcipher.database;

public class SQLiteProxy extends SQLiteCompiledSql {

    public SQLiteProxy(SQLiteDatabase db, String sql) {
        super(db, sql);
    }

    public void setupStub() {
        nStatement = Long.MAX_VALUE;
    }

}

SQLCipher version (can be identified by executing PRAGMA cipher_version;):
4.4.2 community

SQLCipher for Android version:
4.4.2

Room version:
2.3.0-beta01

My guess would be how Android handles GC and especially finalize() on version API 24-25.
Since there is DB lock() call that blocks/await thread this causes watchdog to throw exception.
I've checked generated Room code and I don't see where the cursor can be not closed.
Not sure when the compiled statement is not cached to emulate the scenario.
However, it happens in normal code execution with extensive concurrent work and multiple transactions.

Can releaseSqlStatement be removed from finalize or handled in a different way?

@oleksandr-semenov

Hi @oleksandr-semenov

Thanks for sharing this. By chance have you tried to integrate this scenario within the SQLCipher for Android test suite? It might streamline both verification and testing of any changes made to address the issue. Thanks!

@developernotes

Hi @developernotes will try doing that. Should I open PR with the test?

@oleksandr-semenov

Hi @oleksandr-semenov

Excellent, that would be great. Thanks!

Now I know how to reproduce this using Room.

Requirements:
Use Android API 24-25

Steps:
Make a statement for DAO like

    @Query("DELETE FROM XXX WHERE id IN (:ids)")
    abstract suspend fun deleteXXX(ids: List<Long>): Int

Seems that this query doesn't work with Cursor. Hence, cursor.close() will not be called.
Room generated code:

 @Override
  public Object deleteXXX(final List<Long> localIds,
      final Continuation<? super Integer> p1) {
    return CoroutinesRoom.execute(__db, true, new Callable<Integer>() {
      @Override
      public Integer call() throws Exception {
        StringBuilder _stringBuilder = StringUtil.newStringBuilder();
        _stringBuilder.append("DELETE FROM XXX WHERE local_id IN (");
        final int _inputSize = localIds.size();
        StringUtil.appendPlaceholders(_stringBuilder, _inputSize);
        _stringBuilder.append(")");
        final String _sql = _stringBuilder.toString();
        final SupportSQLiteStatement _stmt = __db.compileStatement(_sql);
        int _argIndex = 1;
        for (Long _item : localIds) {
          if (_item == null) {
            _stmt.bindNull(_argIndex);
          } else {
            _stmt.bindLong(_argIndex, _item);
          }
          _argIndex ++;
        }
        __db.beginTransaction();
        try {
          final java.lang.Integer _result = _stmt.executeUpdateDelete();
          __db.setTransactionSuccessful();
          return _result;
        } finally {
          __db.endTransaction();
        }
      }
    }, p1);
  }

Make X times calls of this function(X >= 2).
X >= 2 because the first statement will be cached, which means not accessible for GC. But second will be checked by SQLiteDatabase cache and omitted(accessible for GC)

Right after execution in another thread/method run transaction that runs > 10 sec and do memory intensive job.
Observer exception.

What happens:

App runs 2 queries, 1st SQLiteCompiledSql is cached, 2nd is available for GC
In another method/thread transaction runs for a long and blocks DB
When GC starts and tries to free memory from 2nd statement it calls finalize()
finalize() awaits the end of the transaction(s) because of release method call that attempts to acquire the lock for DB
In 10-30 sec demon watchdog throws an exception

I'll try to add this to your test suite, not sure if I need this whole test or just emulating available for GC SQLiteCompiledSql is enough

@oleksandr-semenov

Hi @oleksandr-semenov

That is a great find! Having this within the test suite would be excellent, please let us know if you run into any troubles.

@developernotes

@developernotes I've created PR sqlcipher/sqlcipher-android-tests#38

@oleksandr-semenov

Hi @oleksandr-semenov

We will look into the reported issue, thank you!

I see this crash issue happening, when inserting 15000 rows CSV files data. It worked fine with inserting 500 rows in a CSV file.

Thanks

@developernotes

@developernotes
@oleksandr-semenov
I also face this crash for a long time. Also use Room. And I don't insert several thousand rows (as was described by @praveenb ), ordinary work with the database, very few entries.
I tried to fix it by replacing lock() with tryLock() when locking the database SQLiteDatabase in sqlcipher java code (I compiled sqlcipher lib by myself into .so-files instead of import the lib directly in build.gradle in order to try to fix the crash). It seems to me that it worked. At least I don't see this crash in Crashlytics anymore, but the other two crashes appeared:

net.sqlcipher.database.SQLiteDatabase - Fatal Exception: net.sqlcipher.database.SQLiteException cannot start a transaction within a transaction: BEGIN EXCLUSIVE
net.sqlcipher.database.SQLiteCompiledSql - Fatal Exception: net.sqlcipher.database.SQLiteException file is not a database: , while compiling: select count(*) from sqlite_master

This crash I also see in Android 10 devices

@developernotes

@developernotes Is there any updates on this issue ? Because of this issue now our app user facing usability issues.

Hello, it looks like there has been no activity on this issue recently. Has the issue been fixed, or does it still require the community's attention? This issue may be closed if no further activity occurs. You may also label this issue as "bug", "enhancement", or "security" and I will leave it open. Thank you for your contributions.

@developernotes

Hi @developernotes
This is an issue for us still and seems for other developers also. Are there any plans to fix it?

@oleksandr-semenov

Hello @oleksandr-semenov

Unfortunately, I have still been unable to reproduce this in any emulator on my host machine. Since you are able to reproduce it, would you try a modification to your test scenario to see if the same or different behavior is observed? In your test scenario where you are able to reproduce the issue, after constructing the SQLiteDatabase instance, call setLockingEnabled(false) on the connection. I'm curious if you still experience the issue.

Ok I will try doing that and will let you know.

@developernotes

@developernotes I've updated my test PR. Please take a look.

Hello, it looks like there has been no activity on this issue recently. Has the issue been fixed, or does it still require the community's attention? This issue may be closed if no further activity occurs. You may also label this issue as "bug", "enhancement", or "security" and I will leave it open. Thank you for your contributions.

hi, the issue is not fixed, it still requires the attention.

Hello, it looks like there has been no activity on this issue recently. Has the issue been fixed, or does it still require the community's attention? This issue may be closed if no further activity occurs. You may also label this issue as "bug", "enhancement", or "security" and I will leave it open. Thank you for your contributions.

Closing this issue after a prolonged period of inactivity. If this issue is still present in the latest release, please feel free to reopen with up-to-date information.

@developernotes

This issue seems to be closed due to inactivity but issue still persist for us. @developernotes can you please provide update here?

@lalchand92

Hi @lalchand92,

A change was pushed to master on July 8, 2021 to remove the locking within the finalizer of SQLiteCompiledSql. Would you please build this locally and let us know if it resolves your issue?

@developernotes

@developernotes I am still seeing this issue in 4.5.2 version. Looks like still issue exist.

@parasgupta93

Hello @parasgupta93,

Would you open a new ticket with specific details about what your application is doing which causes the error? Additionally, please review the questions in the template as that will help diagnose the issue.

Navigation Menu

Repository navigation

java.util.concurrent.TimeoutException: net.sqlcipher.database.SQLiteCompiledSql.finalize() timed out after 10 seconds #537

Expected Behavior

Actual Behavior

Steps to Reproduce

Metadata

Assignees

Labels

Type

Projects

Milestone

Relationships

Development

java.util.concurrent.TimeoutException: net.sqlcipher.database.SQLiteCompiledSql.finalize() timed out after 10 seconds #537

Description

Expected Behavior

Actual Behavior

Steps to Reproduce

Activity

developernotes commented on Feb 15, 2021

oleksandr-semenov commented on Feb 15, 2021

developernotes commented on Feb 15, 2021

oleksandr-semenov commented on Feb 16, 2021

developernotes commented on Feb 16, 2021

oleksandr-semenov commented on Feb 16, 2021

developernotes commented on Feb 16, 2021

praveenb commented on Mar 3, 2021

alla2040 commented on Apr 6, 2021

srb9181 commented on Apr 26, 2021

stale commented on Jun 3, 2021

oleksandr-semenov commented on Jun 4, 2021

developernotes commented on Jun 4, 2021

oleksandr-semenov commented on Jun 4, 2021

oleksandr-semenov commented on Jun 11, 2021

stale commented on Jun 26, 2021

alla2040 commented on Jun 26, 2021

stale commented on Jul 11, 2021

stale commented on Aug 3, 2021

lalchand92 commented on Oct 8, 2021

developernotes commented on Oct 8, 2021

parasgupta93 commented on Feb 27, 2023

developernotes commented on Feb 27, 2023

Metadata

Metadata

Assignees

Labels

Type

Projects

Milestone

Relationships

Development

Issue actions