CBL freezes app - Full ANR trace provided

[benjamin_glatzeder]

CBL freezes app - Full Application-Not-Responding trace provided

Linking back to two issues:

Updating a document takes 375x longer after a few updates - App freezes

Android 6 CBL 1.3.0 / 1.3.1 This is the document: { "_sync": { "rev": "14-b9a6b3d8dfc5148ccaca5eaa64a0ceac", "sequence": 7625486, "recent_sequences": [ 7625486 ], "history": { "revs": [ "9-ee2c6688c11d563e469916a26d5ef9a0", "6-83d7b01e1dbcae71d1cc2dbb12f73e25", "8-a680614c6895e72f440c7f3f5e003ebe", "1-cea4e6034b5ed6ee1a2c84ee74400ee7", "3-82510156f3076b1ec68880635659ff5a", "5-23838f8162b9c297b636eb9131c286e9", "7-a24bec629fedc635ce65b3823fac4ae0", "10-5c44d…

Android app freezes because of CBL because of SG/CB Server

Linking this solved issue: Updating a document takes 375x longer after a few updates - App freezes Additional info: I received many emails from users who suddenly had the same issue Can I provide any logs or has lots changed since 4.0 CE and this issue will not appear in later versions?

Here is the part of the trace with CBL which seems to lock something and thus the app freezes. This is after the user pressed a button and app writes to CBL

"main" prio=5 tid=1 TimedWaiting
  | group="main" sCount=1 dsCount=0 obj=0x7554a2e8 self=0xb4876a00
  | sysTid=15179 nice=0 cgrp=default sched=0/0 handle=0xb6fd5de4
  | state=S schedstat=( 5271513220 1433977394 4726 ) utm=429 stm=98 core=3 HZ=100
  | stack=0xbe2c7000-0xbe2c9000 stackSize=8MB
  | held mutexes=
  at java.lang.Object.wait!(Native method)
  - waiting on <0x074f4511> (a java.lang.Object)
  at java.lang.Thread.parkFor$(Thread.java:1220)
  - locked <0x074f4511> (a java.lang.Object)
  at sun.misc.Unsafe.park(Unsafe.java:299)
  at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:198)
  at com.couchbase.lite.internal.database.sqlite.SQLiteConnectionPool.waitForConnection(SQLiteConnectionPool.java:668)
  at com.couchbase.lite.internal.database.sqlite.SQLiteConnectionPool.acquireConnection(SQLiteConnectionPool.java:346)
  at com.couchbase.lite.internal.database.sqlite.SQLiteSession.acquireConnection(SQLiteSession.java:849)
  at com.couchbase.lite.internal.database.sqlite.SQLiteSession.beginTransactionUnchecked(SQLiteSession.java:317)
  at com.couchbase.lite.internal.database.sqlite.SQLiteSession.beginTransaction(SQLiteSession.java:305)
  at com.couchbase.lite.internal.database.sqlite.SQLiteDatabase.beginTransaction(SQLiteDatabase.java:499)
  at com.couchbase.lite.internal.database.sqlite.SQLiteDatabase.beginTransaction(SQLiteDatabase.java:410)
  at com.couchbase.lite.storage.SQLiteStorageEngineBase.beginTransaction(SQLiteStorageEngineBase.java:150)
  at com.couchbase.lite.store.SQLiteStore.beginTransaction(SQLiteStore.java:2309)
  at com.couchbase.lite.store.SQLiteStore.add(SQLiteStore.java:1412)
  at com.couchbase.lite.Database.put(Database.java:1839)
  at com.couchbase.lite.Database.putRevision(Database.java:1789)
  at com.couchbase.lite.Database.putRevision(Database.java:1780)
  at com.couchbase.lite.Document.putProperties(Document.java:523)
  at com.couchbase.lite.UnsavedRevision.save(UnsavedRevision.java:118)
  at com.couchbase.lite.Document.update(Document.java:379)
  at com.myapp.utils.a.a.p.c(CouchShoppingList.java:419)
  at com.myapp.utils.a.b.b(CouchHelper.java:544)
  at com.myapp.shoppingList.shoppingListActivity.a.e.b.b.b(CouchEdit.java:51)
  at com.myapp.shoppingList.shoppingListActivity.a.e.b.b.a(CouchEdit.java:81)
  at com.myapp.shoppingList.shoppingListActivity.a.e.b.l.a(ShoppingListItemCouch.java:190)
  at com.myapp.shoppingList.editItems.activity.own.EditExistingItem$2.onClick(EditExistingItem.java:89)
  at android.view.View.performClick(View.java:5265)
  at android.view.View$PerformClick.run(View.java:21534)
  at android.os.Handler.handleCallback(Handler.java:815)
  at android.os.Handler.dispatchMessage(Handler.java:104)
  at android.os.Looper.loop(Looper.java:207)
  at android.app.ActivityThread.main(ActivityThread.java:5728)
  at java.lang.reflect.Method.invoke!(Native method)
  at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:789)
  at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:679)

I attached the full trace as of size limit - txt is not permitted, uploading as zip file anr-trace.zip (20.8 KB)

What else can I do to get this issue acknowledged?

[benjamin_glatzeder]

Here is another ANR trace. Different view in the app. User presses a button, app writes to storage -> ANR

DALVIK THREADS (77):
"main" prio=5 tid=1 TimedWaiting
  | group="main" sCount=1 dsCount=0 obj=0x73f58d40 self=0xb849c9b0
  | sysTid=23247 nice=-1 cgrp=default sched=0/0 handle=0xb6ffabec
  | state=S schedstat=( 17387033101 78651959083 90614 ) utm=1133 stm=605 core=0 HZ=100
  | stack=0xbe66b000-0xbe66d000 stackSize=8MB
  | held mutexes=
  at java.lang.Object.wait!(Native method)
  - waiting on <0x2ca5243d> (a java.lang.Object)
  at java.lang.Thread.parkFor(Thread.java:1233)
  - locked <0x2ca5243d> (a java.lang.Object)
  at sun.misc.Unsafe.park(Unsafe.java:299)
  at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:197)
  at com.couchbase.lite.internal.database.sqlite.SQLiteConnectionPool.waitForConnection(SQLiteConnectionPool.java:668)
  at com.couchbase.lite.internal.database.sqlite.SQLiteConnectionPool.acquireConnection(SQLiteConnectionPool.java:346)
  at com.couchbase.lite.internal.database.sqlite.SQLiteSession.acquireConnection(SQLiteSession.java:849)
  at com.couchbase.lite.internal.database.sqlite.SQLiteSession.beginTransactionUnchecked(SQLiteSession.java:317)
  at com.couchbase.lite.internal.database.sqlite.SQLiteSession.beginTransaction(SQLiteSession.java:305)
  at com.couchbase.lite.internal.database.sqlite.SQLiteDatabase.beginTransaction(SQLiteDatabase.java:499)
  at com.couchbase.lite.internal.database.sqlite.SQLiteDatabase.beginTransaction(SQLiteDatabase.java:410)
  at com.couchbase.lite.storage.SQLiteStorageEngineBase.beginTransaction(SQLiteStorageEngineBase.java:150)
  at com.couchbase.lite.store.SQLiteStore.beginTransaction(SQLiteStore.java:2309)
  at com.couchbase.lite.store.SQLiteStore.add(SQLiteStore.java:1412)
  at com.couchbase.lite.Database.put(Database.java:1839)
  at com.couchbase.lite.Database.putRevision(Database.java:1789)
  at com.couchbase.lite.Database.putRevision(Database.java:1780)
  at com.couchbase.lite.Document.putProperties(Document.java:523)
  at com.couchbase.lite.UnsavedRevision.save(UnsavedRevision.java:118)
  at com.couchbase.lite.Document.update(Document.java:379)
  at com.myapp.utils.a.a.p.a(CouchShoppingList.java:339)
  at com.myapp.utils.a.b.g(CouchHelper.java:548)
  at com.myapp.management.activities.allItems.a.c.b.a(CouchEdit.java:84)
  at com.myapp.management.activities.allItems.a.c.b.a(CouchEdit.java:56)
  at com.myapp.management.activities.allItems.a.c.f.a(ItemCouch.java:162)
  at com.myapp.shoppingList.editItems.activity.own.EditExistingItem$2.onClick(EditExistingItem.java:99)
  at android.view.View.performClick(View.java:4793)
  at android.view.View$PerformClick.run(View.java:19959)
  at android.os.Handler.handleCallback(Handler.java:739)
  at android.os.Handler.dispatchMessage(Handler.java:95)
  at android.os.Looper.loop(Looper.java:135)
  at android.app.ActivityThread.main(ActivityThread.java:5596)
  at java.lang.reflect.Method.invoke!(Native method)
  at java.lang.reflect.Method.invoke(Method.java:372)
  at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:960)
  at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:755)

Another one with different trace, but again with locks and mutexes

suspend all histogram:    Sum: 4.393ms 99% C.I. 2us-1193.280us Avg: 72.016us Max: 1376us
DALVIK THREADS (55):
"CBLReplicationExecutor-http://<BACKEND-URL>-pull-097f8" prio=5 tid=40 Runnable
  | group="main" sCount=0 dsCount=0 obj=0x135dc340 self=0x9c1fa400
  | sysTid=16304 nice=0 cgrp=default sched=0/0 handle=0x9b0f5930
  | state=R schedstat=( 13814017746 1723448144 7157 ) utm=1343 stm=38 core=3 HZ=100
  | stack=0x9aff3000-0x9aff5000 stackSize=1038KB
  | held mutexes= "mutator lock"(shared held)
  at java.lang.ThreadLocal.get(ThreadLocal.java:65)
  at com.couchbase.lite.internal.database.sqlite.SQLiteDatabase.getThreadSession(SQLiteDatabase.java:350)
  at com.couchbase.lite.internal.database.sqlite.SQLiteProgram.getSession(SQLiteProgram.java:107)
  at com.couchbase.lite.internal.database.sqlite.SQLiteStatement.executeInsert(SQLiteStatement.java:89)
  at com.couchbase.lite.internal.database.sqlite.SQLiteDatabase.insertWithOnConflict(SQLiteDatabase.java:1455)
  at com.couchbase.lite.internal.database.sqlite.SQLiteDatabase.insertOrThrow(SQLiteDatabase.java:1351)
  at com.couchbase.lite.storage.SQLiteStorageEngineBase.insertOrThrow(SQLiteStorageEngineBase.java:195)
  at com.couchbase.lite.store.SQLiteStore.insertRevision(SQLiteStore.java:2663)
  at com.couchbase.lite.store.SQLiteStore.forceInsert(SQLiteStore.java:1722)
  at com.couchbase.lite.Database.forceInsert(Database.java:1912)
  at com.couchbase.lite.replicator.PullerInternal$9.run(PullerInternal.java:580)
  at com.couchbase.lite.store.SQLiteStore.runInTransaction(SQLiteStore.java:717)
  at com.couchbase.lite.replicator.PullerInternal.insertDownloads(PullerInternal.java:562)
  at com.couchbase.lite.replicator.PullerInternal$2.process(PullerInternal.java:127)
  at com.couchbase.lite.support.Batcher.processNow(Batcher.java:396)
  - locked <0x04bbfdf7> (a java.lang.Object)
  at com.couchbase.lite.support.Batcher.access$300(Batcher.java:29)
  at com.couchbase.lite.support.Batcher$2.run(Batcher.java:330)
  at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:423)
  at java.util.concurrent.FutureTask.run(FutureTask.java:237)
  at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:154)
  at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:269)
  at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1113)
  at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:588)
  at java.lang.Thread.run(Thread.java:818)

[hideki]

Hi @benjamin_glatzeder,

anr-trace.zip is not downloadable. Can you repost it? And also I’d like to check entire thread-dump to find which thread blocks others.

In addition, can you share following?

• CBL version
• Android OS version

Thanks!

[benjamin_glatzeder]

CBL 1.3.0
Andoid 4.4, 5.1, 6.0
Source of traces and other info is Google Play Developer Console

I created a private Github gist and will send you the link as direct message if this is OK

[jens]

Hi Benjamin, it’s better for everyone if you file bug reports in our issue tracker rather than just as forum posts. The appropriate Github repo is https://github.com/couchbase/couchbase-lite-java-core. Thanks.

[benjamin_glatzeder]

@jens that’s alright, will do that!

[benjamin_glatzeder]

@jens @hideki I created a new issue here

[hideki]

Generic recommendation:

It seems pull replication is busy because of document size is large or large number of documents. And it keeps holding SQLite write connection. The write connection is only one. Therefore, main thread is blocked by SQLite write operation.

I recommend to use Database.runAsync(…) or Android’s AsyncTask to store document in Couchbase lite instead of storing document from main thread.

[benjamin_glatzeder]

I created a sample app which mimics my app’s data modell. Data is only saved locally. In extreme scenario updating takes less than 1 second. This is far away from an ANR although it is an extreme scenario. Please see my detailed comment on the Github issue

Might this be related: _changes feed latency is very high

[benjamin_glatzeder]

Issue is fixed by implementing client-side conflict solving and pruning of old revisions via SG