Patch: Fix SQLiteCursor locking issue.

[promeG]

Hi, I have encountered deadlock problem when applying SQLCipher to my application.

There is a closed issue about it : #97

I compared the lock method used in SQLCipher with AOSP4.0.1, and found that there are some difference.

After doing some changes, I finally get rid of deadlock problem. Here is the patch: https://github.com/promeG/SQLCipher-Android-Fix-Deadlock-Patch

I hope it can help with other people who have the same problem.

SQLCipher is a great project, thank you for your hard work!

[developernotes]

Hello promeG,

Thank you for your interest in SQLCipher for Android. We would prefer a pull request for changes like this, as it helps the integration process as well as provided proper attribution of the changes within the source tree. Also, it would be beneficial if there was test coverage for this type of change within the test suite. Thanks!

[promeG]

Hi, dheerajb

Sorry I can't find the problem based on your log, maybe you can try my modified libraries?

I have uploaded them on: https://github.com/promeG/SQLCipher-Android-Fix-Deadlock-Patch/tree/master/libs

[dheerajb]

Hey promeG

you mentioned "I compared the lock method used in SQLCipher with AOSP4.0.1, and found that there are some difference."

Can you please elaborate which file in AOSP you compared to?

[promeG]

Hi dheerajb

I went through with package "android.database.sqlite" in AOSP, and compared SQLCipher's SQLiteDatabase.java and SQLiteProgram.java. May be there are other classes which implement lock() improperly.

An online refrence to AOSP code:
http://grepcode.com/file/repository.grepcode.com/java/ext/com.google.android/android/4.0.3_r1/android/database/sqlite/SQLiteDatabase.java#SQLiteDatabase
http://grepcode.com/file/repository.grepcode.com/java/ext/com.google.android/android/4.0.3_r1/android/database/sqlite/SQLiteProgram.java#SQLiteProgram

Hope this will help you.

[dheerajb]

Still no luck.

I have one question. I understand we should avoid db operations in MAIN Thread, but a simple query should not cause an ANR. It was fine when we were not using SQLCipher.

Now the same logic throws an ANR when we switched to SQLCipher.

I am surprised why lock() is taking so much time to cause an ANR.

"main" prio=5 tid=1 WAIT

| group="main" sCount=1 dsCount=0 obj=0x41b79578 self=0x41ae6a60

| sysTid=6675 nice=0 sched=0/0 cgrp=apps handle=1074970620

| state=S schedstat=( 11494402761 2196695859 19554 ) utm=811 stm=337 core=3

at java.lang.Object.wait(Native Method)

• waiting on <0x41b79978> (a java.lang.VMThread) held by tid=1 (main)

  at java.lang.Thread.parkFor(Thread.java:1205)

  at sun.misc.Unsafe.park(Unsafe.java:325)

  at java.util.concurrent.locks.LockSupport.park(LockSupport.java:159)

  at java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:810)

  at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireQueued(AbstractQueuedSynchronizer.java:843)

  at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(AbstractQueuedSynchronizer.java:1173)

  at java.util.concurrent.locks.ReentrantLock$FairSync.lock(ReentrantLock.java:198)

  at java.util.concurrent.locks.ReentrantLock.lock(ReentrantLock.java:259)

  at net.sqlcipher.database.SQLiteDatabase.lock(SQLiteDatabase.java:459)

  at net.sqlcipher.database.SQLiteDatabase.addSQLiteClosable(SQLiteDatabase.java:381)

  at net.sqlcipher.database.SQLiteProgram.(SQLiteProgram.java:65)

  at net.sqlcipher.database.SQLiteQuery.(SQLiteQuery.java:49)

  at net.sqlcipher.database.SQLiteDirectCursorDriver.query(SQLiteDirectCursorDriver.java:42)

  at net.sqlcipher.database.SQLiteDatabase.rawQueryWithFactory(SQLiteDatabase.java:1450)

  at net.sqlcipher.database.SQLiteDatabase.queryWithFactory(SQLiteDatabase.java:1330)

  at net.sqlcipher.database.SQLiteDatabase.query(SQLiteDatabase.java:1284)

  at net.sqlcipher.database.SQLiteDatabase.query(SQLiteDatabase.java:1404)

[developernotes]

Hello @dheerajb

If you are able to recreate the issue in isolation, we would be glad to look at it further. Please feel free to create a test case within the SQLCipher for Android test suite and we can delve deeper into what the cause may be. Thanks!

[draak567]

The issue seems to be the way the AOSP email client code interacts with SQLCipher.

In my experience, especially when using Exchange ActiveSync support and a large mailbox with calendar and contact list support, it's not uncommon at startup for the e-mail SQL database to be accessed by several threads simultaneously performing both read and write operations.

You can see the code that uses the SQL database here:
http://grepcode.com/file/repository.grepcode.com/java/ext/com.google.android/android-apps/4.0.1_r1/com/android/email/provider/EmailProvider.java

In that scenario, replacing the Android standard SQLiteDatabase object by SQLCipher's occasionally leads to a deadlock with at least 10-15 threads deadlocked on the database object's lock. Because of the email client's design, which accesses the database from the UI thread in the Welcome activity, the deadlock eventually leads to an ANR.

We ran into this problem when we attempted to integrate the AOSP e-mail client into our own application with the additional requirement that the database be encrypted.

The issue occurred more often the more emails/contacts/calendar entries were present in the user's Exchange inbox and the slower the target handset was.

[dheerajb]

Sorry was trying to edit my original post and deleted by mistake.
( Is their a way to retrieve it?)

Here goes the issue we are facing. Exactly as pointed out in the post. https://github.com/sqlcipher/android-database-sqlcipher /issues/97.

Thanks draak567 for the insight. You are right we are getting in deadlcok often. Will keep posted.
Now we will see if we can remove all db access from MAIN thread, but this change will be humungous.

[dheerajb]

1. What I tried is disabled setLockingEnabled to false and then for synchronization purpose used Reentrant locks in android EmailProvider.java (In my app). Still I got a deadlock while acquiring lock().

@developernotes : We are working on if we can isolate the issue. But the issue happens with google implementation of Email on android, so currently finding it difficult to isolate.

2. I tried one more thing.
   deadlock was also happening on Map<String, SyncUpdateInfo> mSyncUpdateInfo. So I removed synchronized for mSyncUpdateInfo ans introduced Reentrant lock for that, but still no progress.

Can it be a dvm issue. Please see this link http://bugs.java.com/bugdatabase/view_bug.do?bug_id=6865591.

[dheerajb]

Hi

I made following changes to the the SQLitedatbase.java. But the issue still exists. Can you please verify if this is a valid change (though our issue not resolved)
Made this change throughout the file. Was thinking if in-case lock was acquired but never released.

orig:
public int getVersion() {
SQLiteStatement prog = null;
lock();
if (!isOpen()) {
throw new IllegalStateException("database not open");
}
try {
prog = new SQLiteStatement(this, "PRAGMA user_version;");
long version = prog.simpleQueryForLong();
return (int) version;
} finally {
if (prog != null) prog.close();
unlock();
}
}

change 👍
public int getVersion() {
SQLiteStatement prog = null;

    try {
       lock();
        if (!isOpen()) {
            throw new IllegalStateException("database not open");
        }
        prog = new SQLiteStatement(this, "PRAGMA user_version;");
        long version = prog.simpleQueryForLong();
        return (int) version;
    } finally {
        if (prog != null) prog.close();
        unlock();
    }
}

[dheerajb]

Hi draak567

were you able to solve the issue when you tried integrating AOSP Email with your app??

[developernotes]

Hi @dheerajb

Could you try removing the lock()/unlock() statments akin to the patch file supplied here, making the methods sychronized and run it through your scenario to see if there is any change in behavior? Thanks!

[dheerajb]

Hi @developernotes

I had tried this patch by @promeG , still we were in ANR.
Currently I am trying running SQLCiher in SingleThread support mode.
For this I am doing setLockingEnabled(false). This should disable Reentrant lock mechanism.
Further I am introducing synchronization on a object in our providers.

Now ANR is caused due to 👎

at java.lang.Object.wait(Native Method)

• waiting on <0x424f65b8> (a java.lang.VMThread) held by tid=26 (__eas[Exchange ActiveSync])

  at java.lang.Thread.parkFor(Thread.java:1231)

  at sun.misc.Unsafe.park(Unsafe.java:323)

  at java.util.concurrent.locks.LockSupport.park(LockSupport.java:157)

  at java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:813)

  at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireQueued(AbstractQueuedSynchronizer.java:846)

  at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(AbstractQueuedSynchronizer.java:1176)

  at java.util.concurrent.locks.ReentrantLock$FairSync.lock(ReentrantLock.java:200)

  at java.util.concurrent.locks.ReentrantLock.lock(ReentrantLock.java:261)

  at net.sqlcipher.database.SQLiteDatabase.lockForced(SQLiteDatabase.java:478)

  at net.sqlcipher.database.SQLiteDatabase.beginTransactionWithListener(SQLiteDatabase.java:587)

  at net.sqlcipher.database.SQLiteDatabase.beginTransaction(SQLiteDatabase.java:562)

[developernotes]

Hello @dheerajb

SQLCipher for Android is being complied with serialized threading mode, within the Java library however, I would be curious if you removed the various mLock.lock() and mLock.unlock() operations entirely how the application would behave. It sounds like the application may still be doing too much on the UI thread given the ANR.

[dheerajb]

Hi @developernotes

We tried disabling the locks by calling SQLiteDatabase::setLockingEnabled(false). But we were not able to completely remove the "mLock" dependency. Since, lockForced() is making use of the same, and also we observed calls like "mLock.getHoldCount()" in beginTransaction(). So, we were not able to comment out the mLock.

And also some times we observed that our UI was not updated. When we tried to analyze by collecting the dumpstate, we observed other threads (main thread was not involved) waiting for the lock (Similar to above pasted call stacks). UI was empty as the helper threads like Async tasks or Runnables which were trying to fetch data from the DB, were waiting on lock().

One point to note here is that we always dont get an ANR but our other threads/synctasks wait to acquire lock().

Any suggestions.
Thanks for your response