Closed bpolanec closed 5 years ago
The crash is in JNI, so this belongs in the Android repo, I think.
It appears that this comment, in the current code, incorrect:
// !!FIXME: There appears to be a heisenbug, here:
// hbase.lite.tes: JNI ERROR (app bug): attempt to use stale Global 0x25e6 (should be 0x25ea)
// hbase.lite.tes: java_vm_ext.cc:542] JNI DETECTED ERROR IN APPLICATION: use of deleted global reference 0x25e6
// hbase.lite.tes: java_vm_ext.cc:542] from void com.couchbase.lite.internal.core.C4Replicator.free(
// long, java.lang.Object, java.lang.Object)
// It was introduced during the massive refactor to clean up the code, 3/13/2019
It is neither a heisenbug, nor was it introduced in 3/13/2019!
I'm seeing exact same crash: https://github.com/couchbase/couchbase-lite-android/issues/1907
From the log, look like they are multiple logs of the same but with different handle objects. Not sure which scenario is causing this.
2019-05-06 12:32:11.392 32047-5948/com.myproject W/CouchbaseLite/NETWORK: WebSocketListener.onFailure() response -> null: java.io.EOFException
2019-05-06 12:32:11.392 32047-5951/com.myproject W/CouchbaseLite/NETWORK: WebSocketListener.onFailure() response -> null: java.io.EOFException
2019-05-06 12:32:11.392 32047-5953/com.myproject W/CouchbaseLite/NETWORK: WebSocketListener.onFailure() response -> null: java.io.EOFException
2019-05-06 12:32:11.394 32047-5949/com.myproject W/CouchbaseLite/NETWORK: WebSocketListener.onFailure() response -> null: java.io.EOFException
2019-05-06 12:32:11.395 32047-5950/com.myproject W/CouchbaseLite/NETWORK: WebSocketListener.onFailure() response -> null: java.io.EOFException
2019-05-06 12:32:11.397 32047-5944/com.myproject W/CouchbaseLite/NETWORK: WebSocketListener.onFailure() response -> null: java.io.EOFException
2019-05-06 12:32:11.412 32047-859/com.myproject W/C4Socket: C4Socket.dispose() handle -> 521114995248
2019-05-06 12:32:11.424 32047-859/com.myproject W/C4Socket: C4Socket.dispose() handle -> 521177982512
2019-05-06 12:32:11.424 32047-857/com.myproject W/C4Socket: C4Socket.dispose() handle -> 521114476720
2019-05-06 12:32:11.427 32047-859/com.myproject W/C4Socket: C4Socket.dispose() handle -> 521114479408
2019-05-06 12:32:11.432 32047-857/com.myproject W/C4Socket: C4Socket.dispose() handle -> 521444477360
2019-05-06 12:32:11.438 32047-859/com.myproject W/C4Socket: C4Socket.dispose() handle -> 521178298288
2019-05-06 12:32:11.438 32047-857/com.myproject W/C4Socket: C4Socket.dispose() handle -> 520600690608
2019-05-06 12:32:11.440 32047-857/com.myproject E/CouchbaseLite/REPLICATOR: {Repl#732}==> N8litecore4repl10ReplicatorE /data/user/0/com.myproject/files/system.cblite2/ ->wss://devmobile.myproject.com:6986/ag-dev/_blipsync @0x793a50f8c8
2019-05-06 12:32:11.448 32047-857/com.myproject E/CouchbaseLite/REPLICATOR: {Repl#732} Got LiteCore error: POSIX error 104 "Connection reset by peer"
2019-05-06 12:32:11.490 32047-859/com.myproject E/CouchbaseLite/REPLICATOR: {Repl#733}==> N8litecore4repl10ReplicatorE /data/user/0/com.myproject/files/system.cblite2/ ->wss://devmobile.myproject.com:6986/ag-dev/_blipsync @0x792d6f26c8
2019-05-06 12:32:11.492 32047-859/com.myproject E/CouchbaseLite/REPLICATOR: {Repl#733} Got LiteCore error: POSIX error 104 "Connection reset by peer"
2019-05-06 12:32:11.503 32047-857/com.myproject E/CouchbaseLite/REPLICATOR: {Repl#734}==> N8litecore4repl10ReplicatorE /data/user/0/com.myproject/files/system.cblite2/ ->wss://devmobile.myproject.com:6986/ag-dev/_blipsync @0x793a435dc8
2019-05-06 12:32:11.508 32047-857/com.myproject E/CouchbaseLite/REPLICATOR: {Repl#734} Got LiteCore error: POSIX error 104 "Connection reset by peer"
@bpolanec do you have multiple replicators running?
I think @bmeike has already handled multiple handles in his PR.
@pasin yep I have multiple replicators running at time of crash:
pull replicators: Replicator[<* Database@437dced{name='db_one'} URLEndpoint{url=wss://myproject.com:6986/ag-dev}] 1 channel registered continuous pull
Replicator[<* Database@8425ae9{name='db_one'} URLEndpoint{url=wss://myproject.com:6986/ag-dev}] 5 channels registered. continuous pull
push replicators: Replicator[*> Database@d96ca3b{name='system'} URLEndpoint{url=wss://myproject.com:6986/ag-dev}] no channels. continous push with push filter
Replicator[*> Database@36e8ca0{name='db_one'} URLEndpoint{url=wss://myproject.com:6986/ag-dev}] no channels continous push with push filter
I have been migrating my code to 2.5 and haven't experienced this issue so far, it is a bit worrying though so I am keen to know that it is resolved before making my update live. Are you able to provide a timeframe for a fix for this?
I have been working on a fix for this issue. If any of you would be willing to try building
https://github.com/couchbase/couchbase-lite-android-ce
... I'd be very interested in hearing your about your experience.
I tried to run it, but noticed two differences:
a) Slight API Change ( cblite init necessary, DatabaseConfiguration misses context param ) compared to Iridium / 2.5 b) Fleece error:
2019-05-10 11:55:01.849 19083-19230/? E/CouchbaseLite/REPLICATOR: {Repl#14} Got LiteCore error: WebSocket error 401 "Unauthorized"
2019-05-10 11:55:01.849 19083-19229/? E/CouchbaseLite/NETWORK: CBLWebSocket.socket_open()
2019-05-10 11:55:01.849 19083-19229/? W/CouchbaseLite/NETWORK: C4Socket.open() socket -> 546974411072
2019-05-10 11:55:01.849 19083-19229/? W/CouchbaseLite/NETWORK: C4Socket.open() clazz -> com.couchbase.lite.internal.replicator.CBLWebSocket
2019-05-10 11:55:01.849 19083-19229/? E/CouchbaseLite/NETWORK: CBLWebSocket.socket_open()
2019-05-10 11:55:01.915 19083-19233/? W/CouchbaseLite/NETWORK: C4Socket.open() socket -> 546974413312
2019-05-10 11:55:01.916 19083-19233/? W/CouchbaseLite/NETWORK: C4Socket.open() clazz -> com.couchbase.lite.internal.replicator.CBLWebSocket
2019-05-10 11:55:01.916 19083-19233/? E/CouchbaseLite/NETWORK: CBLWebSocket.socket_open()
2019-05-10 11:55:01.947 19083-19164/? A/libc: Fatal signal 11 (SIGSEGV), code 1, fault addr 0x0 in tid 19164 (mqt_native_modu)
2019-05-10 11:55:02.039 19260-19260/? A/DEBUG: *** *** *** *** *** *** *** *** *** *** *** *** *** *** *** ***
2019-05-10 11:55:02.040 19260-19260/? A/DEBUG: Build fingerprint: 'M3/msm8953_64/msm8953_64:7.1.1/NMF26F/Data.B05031742:user/release-keys'
2019-05-10 11:55:02.040 19260-19260/? A/DEBUG: Revision: '0'
2019-05-10 11:55:02.040 19260-19260/? A/DEBUG: ABI: 'arm64'
2019-05-10 11:55:02.040 19260-19260/? A/DEBUG: pid: 19083, tid: 19164, name: mqt_native_modu >>myapp.debug <<<
2019-05-10 11:55:02.040 19260-19260/? A/DEBUG: signal 11 (SIGSEGV), code 1 (SEGV_MAPERR), fault addr 0x0
2019-05-10 11:55:02.040 19260-19260/? A/DEBUG: x0 0000000000000000 x1 0000007f6c113a54 x2 0000007f52c50f00 x3 0000007f8004e600
2019-05-10 11:55:02.040 19260-19260/? A/DEBUG: x4 0000007f6c113ee8 x5 0000007f720157e9 x6 0000007f7253d89c x7 0000000000000000
2019-05-10 11:55:02.040 19260-19260/? A/DEBUG: x8 72e1505aca897e7a x9 0000007f6c11a4e8 x10 0000000000430000 x11 0000007f8d2af67c
2019-05-10 11:55:02.040 19260-19260/? A/DEBUG: x12 0000007f8d2af6d0 x13 0000007f8d2af724 x14 0000007f8d2af784 x15 0000000000000000
2019-05-10 11:55:02.040 19260-19260/? A/DEBUG: x16 0000007f561f4008 x17 0000007f5602ab98 x18 0000000070a14344 x19 0000007f6c11a4e8
2019-05-10 11:55:02.040 19260-19260/? A/DEBUG: x20 0000007f52c50f00 x21 0000007f8004e600 x22 0000007f6c113cfc x23 0000007f720157e9
2019-05-10 11:55:02.040 19260-19260/? A/DEBUG: x24 0000000000000008 x25 72e1505aca897e7a x26 0000007f8004e698 x27 72e1505aca897e7a
2019-05-10 11:55:02.040 19260-19260/? A/DEBUG: x28 0000000000000002 x29 0000007f6c1139b0 x30 0000007f56012988
2019-05-10 11:55:02.040 19260-19260/? A/DEBUG: sp 0000007f6c113990 pc 0000007f5602abb0 pstate 0000000020000000
2019-05-10 11:55:02.043 19260-19260/? A/DEBUG: backtrace:
2019-05-10 11:55:02.043 19260-19260/? A/DEBUG: #00 pc 0000000000303bb0 /data/app/myapp/lib/arm64/libLiteCoreJNI.so (_ZNK6fleece4impl5Value8asStringEv+24)
2019-05-10 11:55:02.043 19260-19260/? A/DEBUG: #01 pc 00000000002eb984 /data/app/myapp/lib/arm64/libLiteCoreJNI.so (_ZNK6fleece4impl4Dict8iterator9keyStringEv+20)
2019-05-10 11:55:02.043 19260-19260/? A/DEBUG: #02 pc 00000000002e4fd4 /data/app/myapp/lib/arm64/libLiteCoreJNI.so (FLDictIterator_GetKeyString+28)
2019-05-10 11:55:02.043 19260-19260/? A/DEBUG: #03 pc 00000000001124bc /data/app/myapp/lib/arm64/libLiteCoreJNI.so (Java_com_couchbase_lite_internal_fleece_FLDictIterator_getKeyString+20)
2019-05-10 11:55:02.043 19260-19260/? A/DEBUG: #04 pc 00000000011d29d4 /data/app/myapp/oat/arm64/base.odex (offset 0x1097000)
I launched the App with an existing Database File from Iridium Release. It doesn't seem to started a Database Update, just failed to read a document.
It could be benificial to handle this as an 2.5 / iridium patch and not test / build it solely on top of master. I guess it will land in a bugfix release anyway
One Other Hint: In the logs above there is a 401 visible - this isn't happening in iridium / 2.5. Same Settings, Same Data.
I have downloaded the open source zip file for android from the download page ... is this bug in that release? or is this specific to a specific branch of development? If it is in the downloadable file then surely this must be critical?
I can consistently replicate the issue when Sync Gateway responds with anything other than 101. com.couchbase.lite:couchbase-lite-android:2.5.0 Android P API 28
2019-05-15 11:01:49.179 4396-4416/my.app.android E/CouchbaseLite/REPLICATOR: {Repl#12}==> N8litecore4repl10ReplicatorE /data/user/0/my.app.android/files/database_prod.cblite2/ ->wss://someurl/database_prod/_blipsync @0x74a2e132c8
2019-05-15 11:01:49.180 4396-4416/my.app.android E/CouchbaseLite/REPLICATOR: {Repl#12} Got LiteCore error: WebSocket error 502 "Bad Gateway"
2019-05-15 11:01:49.183 4396-4424/my.app.android E/vations.androi: JNI ERROR (app bug): accessed deleted Global 0x26d2
2019-05-15 11:01:49.189 4396-4415/my.app.android W/C4Socket: C4Socket.open() socket -> 500951082928
2019-05-15 11:01:49.190 4396-4415/my.app.android W/C4Socket: C4Socket.open() clazz -> com.couchbase.lite.internal.replicator.CBLWebSocket
2019-05-15 11:01:49.190 4396-4415/my.app.android E/CouchbaseLite/NETWORK: CBLWebSocket.socket_open()
2019-05-15 11:01:49.226 4396-4424/my.app.android A/vations.androi: java_vm_ext.cc:542] JNI DETECTED ERROR IN APPLICATION: use of deleted global reference 0x26d2
2019-05-15 11:01:49.226 4396-4424/my.app.android A/vations.androi: java_vm_ext.cc:542] from void com.couchbase.litecore.C4Replicator.free(long, java.lang.Object, java.lang.Object)
2019-05-15 11:01:49.226 4396-4424/my.app.android A/vations.androi: java_vm_ext.cc:542] "ReplicatorListenerThread" prio=5 tid=15 Runnable
2019-05-15 11:01:49.226 4396-4424/my.app.android A/vations.androi: java_vm_ext.cc:542] | group="main" sCount=0 dsCount=0 flags=0 obj=0x130034e8 self=0x74b9de7400
2019-05-15 11:01:49.226 4396-4424/my.app.android A/vations.androi: java_vm_ext.cc:542] | sysTid=4424 nice=0 cgrp=default sched=0/0 handle=0x74a19954f0
2019-05-15 11:01:49.226 4396-4424/my.app.android A/vations.androi: java_vm_ext.cc:542] | state=R schedstat=( 12461043 559430 32 ) utm=0 stm=0 core=5 HZ=100
2019-05-15 11:01:49.226 4396-4424/my.app.android A/vations.androi: java_vm_ext.cc:542] | stack=0x74a1892000-0x74a1894000 stackSize=1041KB
2019-05-15 11:01:49.226 4396-4424/my.app.android A/vations.androi: java_vm_ext.cc:542] | held mutexes= "mutator lock"(shared held)
2019-05-15 11:01:49.226 4396-4424/my.app.android A/vations.androi: java_vm_ext.cc:542] native: #00 pc 00000000003c7324 /system/lib64/libart.so (art::DumpNativeStack(std::__1::basic_ostream<char, std::__1::char_traits<char>>&, int, BacktraceMap*, char const*, art::ArtMethod*, void*, bool)+220)
2019-05-15 11:01:49.226 4396-4424/my.app.android A/vations.androi: java_vm_ext.cc:542] native: #01 pc 0000000000495dc0 /system/lib64/libart.so (art::Thread::DumpStack(std::__1::basic_ostream<char, std::__1::char_traits<char>>&, bool, BacktraceMap*, bool) const+352)
2019-05-15 11:01:49.226 4396-4424/my.app.android A/vations.androi: java_vm_ext.cc:542] native: #02 pc 00000000002e85ac /system/lib64/libart.so (art::JavaVMExt::JniAbort(char const*, char const*)+972)
2019-05-15 11:01:49.226 4396-4424/my.app.android A/vations.androi: java_vm_ext.cc:542] native: #03 pc 00000000002e8abc /system/lib64/libart.so (art::JavaVMExt::JniAbortF(char const*, char const*, ...)+180)
2019-05-15 11:01:49.226 4396-4424/my.app.android A/vations.androi: java_vm_ext.cc:542] native: #04 pc 000000000049bab4 /system/lib64/libart.so (art::Thread::DecodeJObject(_jobject*) const+708)
2019-05-15 11:01:49.226 4396-4424/my.app.android A/vations.androi: java_vm_ext.cc:542] native: #05 pc 00000000000fca80 /system/lib64/libart.so (art::(anonymous namespace)::ScopedCheck::CheckInstance(art::ScopedObjectAccess&, art::(anonymous namespace)::ScopedCheck::InstanceKind, _jobject*, bool)+96)
2019-05-15 11:01:49.226 4396-4424/my.app.android A/vations.androi: java_vm_ext.cc:542] native: #06 pc 00000000000fbd74 /system/lib64/libart.so (art::(anonymous namespace)::ScopedCheck::CheckPossibleHeapValue(art::ScopedObjectAccess&, char, art::(anonymous namespace)::JniValueType)+580)
2019-05-15 11:01:49.226 4396-4424/my.app.android A/vations.androi: java_vm_ext.cc:542] native: #07 pc 00000000000fb31c /system/lib64/libart.so (art::(anonymous namespace)::ScopedCheck::Check(art::ScopedObjectAccess&, bool, char const*, art::(anonymous namespace)::JniValueType*)+628)
2019-05-15 11:01:49.226 4396-4424/my.app.android A/vations.androi: java_vm_ext.cc:542] native: #08 pc 00000000000e918c /system/lib64/libart.so (art::(anonymous namespace)::CheckJNI::IsSameObject(_JNIEnv*, _jobject*, _jobject*)+692)
2019-05-15 11:01:49.226 4396-4424/my.app.android A/vations.androi: java_vm_ext.cc:542] native: #09 pc 00000000001100b0 /data/app/my.app.android-oT0OsbCvN9Nf-fQJlUN-xg==/lib/arm64/libLiteCoreJNI.so (???)
2019-05-15 11:01:49.226 4396-4424/my.app.android A/vations.androi: java_vm_ext.cc:542] native: #10 pc 000000000011002c /data/app/my.app.android-oT0OsbCvN9Nf-fQJlUN-xg==/lib/arm64/libLiteCoreJNI.so (Java_com_couchbase_litecore_C4Replicator_free+44)
2019-05-15 11:01:49.226 4396-4424/my.app.android A/vations.androi: java_vm_ext.cc:542] native: #11 pc 0000000000565be0 /system/lib64/libart.so (art_quick_generic_jni_trampoline+144)
2019-05-15 11:01:49.226 4396-4424/my.app.android A/vations.androi: java_vm_ext.cc:542] native: #12 pc 000000000055ce4c /system/lib64/libart.so (art_quick_invoke_static_stub+604)
2019-05-15 11:01:49.226 4396-4424/my.app.android A/vations.androi: java_vm_ext.cc:542] native: #13 pc 00000000000cf760 /system/lib64/libart.so (art::ArtMethod::Invoke(art::Thread*, unsigned int*, unsigned int, art::JValue*, char const*)+232)
2019-05-15 11:01:49.226 4396-4424/my.app.android A/vations.androi: java_vm_ext.cc:542] native: #14 pc 00000000002823b0 /system/lib64/libart.so (art::interpreter::ArtInterpreterToCompiledCodeBridge(art::Thread*, art::ArtMethod*, art::ShadowFrame*, unsigned short, art::JValue*)+344)
2019-05-15 11:01:49.226 4396-4424/my.app.android A/vations.androi: java_vm_ext.cc:542] native: #15 pc 000000000027c36c /system/lib64/libart.so (bool art::interpreter::DoCall<false, false>(art::ArtMethod*, art::Thread*, art::ShadowFrame&, art::Instruction const*, unsigned short, art::JValue*)+948)
2019-05-15 11:01:49.226 4396-4424/my.app.android A/vations.androi: java_vm_ext.cc:542] native: #16 pc 000000000052d91c /system/lib64/libart.so (MterpInvokeStatic+204)
2019-05-15 11:01:49.226 4396-4424/my.app.android A/vations.androi: java_vm_ext.cc:542] native: #17 pc 000000000054f294 /system/lib64/libart.so (ExecuteMterpImpl+14612)
2019-05-15 11:01:49.226 4396-4424/my.app.android A/vations.androi: java_vm_ext.cc:542] native: #18 pc 00000000002b4384 /dev/ashmem/dalvik-classes3.dex extracted in memory from /data/app/my.app.android-oT0OsbCvN9Nf-fQJlUN-xg==/base.apk!classes3.dex (deleted) (com.couchbase.litecore.C4Replicator.free+24)
2019-05-15 11:01:49.226 4396-4424/my.app.android A/vations.androi: java_vm_ext.cc:542] native: #19 pc 0000000000255e68 /system/lib64/libart.so (_ZN3art11interpreterL7ExecuteEPNS_6ThreadERKNS_20CodeItemDataAccessorERNS_11ShadowFrameENS_6JValueEb.llvm.2088410233+496)
2019-05-15 11:01:49.226 4396-4424/my.app.android A/vations.androi: java_vm_ext.cc:542] native: #20 pc 000000000025b9e8 /system/lib64/libart.so (art::interpreter::ArtInterpreterToInterpreterBridge(art::Thread*, art::CodeItemDataAccessor const&, art::ShadowFrame*, art::JValue*)+216)
2019-05-15 11:01:49.226 4396-4424/my.app.android A/vations.androi: java_vm_ext.cc:542] native: #21 pc 000000000027c350 /system/lib64/libart.so (bool art::interpreter::DoCall<false, false>(art::ArtMethod*, art::Thread*, art::ShadowFrame&, art::Instruction const*, unsigned short, art::JValue*)+920)
2019-05-15 11:01:49.226 4396-4424/my.app.android A/vations.androi: java_vm_ext.cc:542] native: #22 pc 000000000052c418 /system/lib64/libart.so (MterpInvokeVirtual+584)
2019-05-15 11:01:49.226 4396-4424/my.app.android A/vations.androi: java_vm_ext.cc:542] native: #23 pc 000000000054f114 /system/lib64/libart.so (ExecuteMterpImpl+14228)
2019-05-15 11:01:49.226 4396-4424/my.app.android A/vations.androi: java_vm_ext.cc:542] native: #24 pc 00000000002a2b58 /dev/ashmem/dalvik-classes3.dex extracted in memory from /data/app/my.app.android-oT0OsbCvN9Nf-fQJlUN-xg==/base.apk!classes3.dex (deleted) (com.couchbase.lite.AbstractReplicator.clearRepl+8)
2019-05-15 11:01:49.226 4396-4424/my.app.android A/vations.androi: java_vm_ext.cc:542] native: #25 pc 0000000000255e68 /system/lib64/libart.so (_ZN3art11interpreterL7ExecuteEPNS_6ThreadERKNS_20CodeItemDataAccessorERNS_11ShadowFrameENS_6JValueEb.llvm.2088410233+496)
2019-05-15 11:01:49.226 4396-4424/my.app.android A/vations.androi: java_vm_ext.cc:542] native: #26 pc 000000000025b9e8 /system/lib64/libart.so (art::interpreter::ArtInterpreterToInterpreterBridge(art::Thread*, art::CodeItemDataAccessor const&, art::ShadowFrame*, art::JValue*)+216)
2019-05-15 11:01:49.226 4396-4424/my.app.android A/vations.androi: java_vm_ext.cc:542] native: #27 pc 000000000027c350 /system/lib64/libart.so (bool art::interpreter::DoCall<false, false>(art::ArtMethod*, art::Thread*, art::ShadowFrame&, art::Instruction const*, unsigned short, art::JValue*)+920)
2019-05-15 11:01:49.226 4396-4424/my.app.android A/vations.androi: java_vm_ext.cc:542] native: #28 pc 000000000052d758 /system/lib64/libart.so (MterpInvokeDirect+296)
2019-05-15 11:01:49.226 4396-4424/my.app.android A/vations.androi: java_vm_ext.cc:542] native: #29 pc 000000000054f214 /system/lib64/libart.so (ExecuteMterpImpl+14484)
2019-05-15 11:01:49.226 4396-4424/my.app.android A/vations.androi: java_vm_ext.cc:542] native: #30 pc 00000000002a1fe4 /dev/ashmem/dalvik-classes3.dex extracted in memory from /data/app/my.app.android-oT0OsbCvN9Nf-fQJlUN-xg==/base.apk!classes3.dex (deleted) (com.couchbase.lite.AbstractReplicator.handleError+116)
2019-05-15 11:01:49.226 4396-4424/my.app.android A/vations.androi: java_vm_ext.cc:542] native: #31 pc 0000000000255e68 /system/lib64/libart.so (_ZN3art11interpreterL7ExecuteEPNS_6ThreadERKNS_20CodeItemDataAccessorERNS_11ShadowFrameENS_6JValueEb.llvm.2088410233+496)
2019-05-15 11:01:49.226 4396-4424/my.app.android A/vations.androi: java_vm_ext.cc:542] native: #32 pc 000000000025b9e8 /system/lib64/libart.so (art::interpreter::ArtInterpreterToInterpreterBridge(art::Thread*, art::CodeItemDataAccessor const&, art::ShadowFrame*, art::JValue*)+216)
2019-05-15 11:01:49.226 4396-4424/my.app.android A/vations.androi: java_vm_ext.cc:542] native: #33 pc 000000000027c350 /system/lib64/libart.so (bool art::interpreter::DoCall<false, false>(art::ArtMethod*, art::Thread*, art::ShadowFrame&, art::Instruction const*, unsigned short, art::JValue*)+920)
2019-05-15 11:01:49.226 4396-4424/my.app.android A/vations.androi: java_vm_ext.cc:542] native: #34 pc 000000000052d758 /system/lib64/libart.so (MterpInvokeDirect+296)
2019-05-15 11:01:49.226 4396-4424/my.app.android A/vations.androi: java_vm_ext.cc:542] native: #35 pc 000000000054f214 /system/lib64/libart.so (ExecuteMterpImpl+14484)
2019-05-15 11:01:49.226 4396-4424/my.app.android A/vations.androi: java_vm_ext.cc:542] native: #36 pc 00000000002a2a4a /dev/ashmem/dalvik-classes3.dex extracted in memory from /data/app/my.app.android-oT0OsbCvN9Nf-fQJlUN-xg==/base.apk!classes3.dex (deleted) (com.couchbase.lite.AbstractReplicator.c4StatusChanged+134)
2019-05-15 11:01:49.226 4396-4424/my.app.android A/vations.androi: java_vm_ext.cc:542] native: #37 pc 0000000000255e68 /system/lib64/libart.so (_ZN3art11interpreterL7ExecuteEPNS_6ThreadERKNS_20CodeItemDataAccessorERNS_11ShadowFrameENS_6JValueEb.llvm.2088410233+496)
2019-05-15 11:01:49.226 4396-4424/my.app.android A/vations.androi: java_vm_ext.cc:542] native: #38 pc 000000000025b9e8 /system/lib64/libart.so (art::interpreter::ArtInterpreterToInterpreterBridge(art::Thread*, art::CodeItemDataAccessor const&, art::ShadowFrame*, art::JValue*)+216)
2019-05-15 11:01:49.226 4396-4424/my.app.android A/vations.androi: java_vm_ext.cc:542] native: #39 pc 000000000027c350 /system/lib64/libart.so (bool art::interpreter::DoCall<false, false>(art::ArtMethod*, art::Thread*, art::ShadowFrame&, art::Instruction const*, unsigned short, art::JValue*)+920)
2019-05-15 11:01:49.226 4396-4424/my.app.android A/vations.androi: java_vm_ext.cc:542] native: #40 pc 000000000052d758 /system/lib64/libart.so (MterpInvokeDirect+296)
2019-05-15 11:01:49.226 4396-4424/my.app.android A/vations.androi: java_vm_ext.cc:542] native: #41 pc 000000000054f214 /system/lib64/libart.so (ExecuteMterpImpl+14484)
2019-05-15 11:01:49.226 4396-4424/my.app.android A/vations.androi: java_vm_ext.cc:542] native: #42 pc 00000000002a297c /dev/ashmem/dalvik-classes3.dex extracted in memory from /data/app/my.app.android-oT0OsbCvN9Nf-fQJlUN-xg==/base.apk!classes3.dex (deleted) (com.couchbase.lite.AbstractReplicator.access$500)
2019-05-15 11:01:49.226 4396-4424/my.app.android A/vations.androi: java_vm_ext.cc:542] native: #43 pc 0000000000255e68 /system/lib64/libart.so (_ZN3art11interpreterL7ExecuteEPNS_6ThreadERKNS_20CodeItemDataAccessorERNS_11ShadowFrameENS_6JValueEb.llvm.2088410233+496)
2019-05-15 11:01:49.226 4396-4424/my.app.android A/vations.androi: java_vm_ext.cc:542] native: #44 pc 000000000025b9e8 /system/lib64/libart.so (art::interpreter::ArtInterpreterToInterpreterBridge(art::Thread*, art::CodeItemDataAccessor const&, art::ShadowFrame*, art::JValue*)+216)
2019-05-15 11:01:49.226 4396-4424/my.app.android A/vations.androi: java_vm_ext.cc:542] native: #45 pc 000000000027c350 /system/lib64/libart.so (bool art::interpreter::DoCall<false, false>(art::ArtMethod*, art::Thread*, art::ShadowFrame&, art::Instruction const*, unsigned short, art::JValue*)+920)
2019-05-15 11:01:49.226 4396-4424/my.app.android A/vations.androi: java_vm_ext.cc:542] native: #46 pc 000000000052d91c /system/lib64/libart.so (MterpInvokeStatic+204)
2019-05-15 11:01:49.226 4396-4424/my.app.android A/vations.androi: java_vm_ext.cc:542] native: #47 pc 000000000054f294 /system/lib64/libart.so (ExecuteMterpImpl+14612)
2019-05-15 11:01:49.226 4396-4424/my.app.android A/vations.androi: java_vm_ext.cc:542] native: #48 pc 00000000002a1944 /dev/ashmem/dalvik-classes3.dex extracted in memory from /data/app/my.app.android-oT0OsbCvN9Nf-fQJlUN-xg==/base.apk!classes3.dex (deleted) (com.couchbase.lite.AbstractReplicator$4$1.run+8)
2019-05-15 11:01:49.226 4396-4424/my.app.android A/vations.androi: java_vm_ext.cc:542] native: #49 pc 0000000000255e68 /system/lib64/libart.so (_ZN3art11interpreterL7ExecuteEPNS_6ThreadERKNS_20CodeItemDataAccessorERNS_11ShadowFrameENS_6JValueEb.llvm.2088410233+496)
2019-05-15 11:01:49.226 4396-4424/my.app.android A/vations.androi: java_vm_ext.cc:542] native: #50 pc 000000000025b9e8 /system/lib64/libart.so (art::interpreter::ArtInterpreterToInterpreterBridge(art::Thread*, art::CodeItemDataAccessor const&, art::ShadowFrame*, art::JValue*)+216)
2019-05-15 11:01:49.226 4396-4424/my.app.android A/vations.androi: java_vm_ext.cc:542] native: #51 pc 000000000027c350 /system/lib64/libart.so (bool art::interpreter::DoCall<false, false>(art::ArtMethod*, art::Thread*, art::ShadowFrame&, art::Instruction const*, unsigned short, art::JValue*)+920)
2019-05-15 11:01:49.226 4396-4424/my.app.android A/vations.androi: java_vm_ext.cc:542] native: #52 pc 000000000052d390 /system/lib64/libart.so (MterpInvokeInterface+1392)
2019-05-15 11:01:49.226 4396-4424/my.app.android A/vations.androi: java_vm_ext.cc:542] native: #53 pc 000000000054f314 /system/lib64/libart.so (ExecuteMterpImpl+14740)
2019-05-15 11:01:49.226 4396-4424/my.app.android A/vations.androi: java_vm_ext.cc:542] native: #54 pc 0000000000112900 /system/framework/boot.vdex (java.util.concurrent.Executors$RunnableAdapter.call+4)
2019-05-15 11:01:49.226 4396-4424/my.app.android A/vations.androi: java_vm_ext.cc:542] native: #55 pc 0000000000255e68 /system/lib64/libart.so (_ZN3art11interpreterL7ExecuteEPNS_6ThreadERKNS_20CodeItemDataAccessorERNS_11ShadowFrameENS_6JValueEb.llvm.2088410233+496)
2019-05-15 11:01:49.226 4396-4424/my.app.android A/vations.androi: java_vm_ext.cc:542] native: #56 pc 000000000025b9e8 /system/lib64/libart.so (art::interpreter::ArtInterpreterToInterpreterBridge(art::Thread*, art::CodeItemDataAccessor const&, art::ShadowFrame*, art::JValue*)+216)
2019-05-15 11:01:49.226 4396-4424/my.app.android A/vations.androi: java_vm_ext.cc:542] native: #57 pc 000000000027c350 /system/lib64/libart.so (bool art::interpreter::DoCall<false, false>(art::ArtMethod*, art::Thread*, art::ShadowFrame&, art::Instruction const*, unsigned short, art::JValue*)+920)
2019-05-15 11:01:49.226 4396-4424/my.app.android A/vations.androi: java_vm_ext.cc:542] native: #58 pc 000000000052d390 /system/lib64/libart.so (MterpInvokeInterface+1392)
2019-05-15 11:01:49.226 4396-4424/my.app.android A/vations.androi: java_vm_ext.cc:542] native: #59 pc 000000000054f314 /system/lib64/libart.so (ExecuteMterpImpl+14740)
2019-05-15 11:01:49.226 4396-4424/my.app.android A/vations.androi: java_vm_ext.cc:542] native: #60 pc 000000000011312e /system/framework/boot.vdex (java.util.concurrent.FutureTask.run+62)
2019-05-15 11:01:49.226 4396-4424/my.app.android A/vations.androi: java_vm_ext.cc:542] native: #61 pc 0000000000255e68 /system/lib64/libart.so (_ZN3art11interpreterL7ExecuteEPNS_6ThreadERKNS_20CodeItemDataAccessorERNS_11ShadowFrameENS_6JValueEb.llvm.2088410233+496)
2019-05-15 11:01:49.226 4396-4424/my.app.android A/vations.androi: java_vm_ext.cc:542] native: #62 pc 000000000025b9e8 /system/lib64/libart.so (art::interpreter::ArtInterpreterToInterpreterBridge(art::Thread*, art::CodeItemDataAccessor const&, art::ShadowFrame*, art::JValue*)+216)
2019-05-15 11:01:49.226 4396-4424/my.app.android A/vations.androi: java_vm_ext.cc:542] native: #63 pc 000000000027c350 /system/lib64/libart.so (bool art::interpreter::DoCall<false, false>(art::ArtMethod*, art::Thread*, art::ShadowFrame&, art::Instruction const*, unsigned short, art::JValue*)+920)
2019-05-15 11:01:49.226 4396-4424/my.app.android A/vations.androi: java_vm_ext.cc:542] native: #64 pc 000000000052caa8 /system/lib64/libart.so (MterpInvokeSuper+1408)
2019-05-15 11:01:49.226 4396-4424/my.app.android A/vations.androi: java_vm_ext.cc:542] native: #65 pc 000000000054f194 /system/lib64/libart.so (ExecuteMterpImpl+14356)
2019-05-15 11:01:49.226 4396-4424/my.app.android A/vations.androi: java_vm_ext.cc:542] native: #66 pc 00000000001157aa /system/framework/boot.vdex (java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run+38)
2019-05-15 11:01:49.226 4396-4424/my.app.android A/vations.androi: java_vm_ext.cc:542] native: #67 pc 0000000000255e68 /system/lib64/libart.so (_ZN3art11interpreterL7ExecuteEPNS_6ThreadERKNS_20CodeItemDataAccessorERNS_11ShadowFrameENS_6JValueEb.llvm.2088410233+496)
2019-05-15 11:01:49.226 4396-4424/my.app.android A/vations.androi: java_vm_ext.cc:542] native: #68 pc 000000000025b9e8 /system/lib64/libart.so (art::interpreter::ArtInterpreterToInterpreterBridge(art::Thread*, art::CodeItemDataAccessor const&, art::ShadowFrame*, art::JValue*)+216)
2019-05-15 11:01:49.226 4396-4424/my.app.android A/vations.androi: java_vm_ext.cc:542] native: #69 pc 000000000027c350 /system/lib64/libart.so (bool art::interpreter::DoCall<false, false>(art::ArtMethod*, art::Thread*, art::ShadowFrame&, art::Instruction const*, unsigned short, art::JValue*)+920)
2019-05-15 11:01:49.226 4396-4424/my.app.android A/vations.androi: java_vm_ext.cc:542] native: #70 pc 000000000052d390 /system/lib64/libart.so (MterpInvokeInterface+1392)
2019-05-15 11:01:49.226 4396-4424/my.app.android A/vations.androi: java_vm_ext.cc:542] native: #71 pc 000000000054f314 /system/lib64/libart.so (ExecuteMterpImpl+14740)
2019-05-15 11:01:49.226 4396-4424/my.app.android A/vations.androi: java_vm_ext.cc:542] native: #72 pc 0000000000117114 /system/framework/boot.vdex (java.util.concurrent.ThreadPoolExecutor.runWorker+162)
2019-05-15 11:01:49.226 4396-4424/my.app.android A/vations.androi: java_vm_ext.cc:542] native: #73 pc 0000000000255e68 /system/lib64/libart.so (_ZN3art11interpreterL7ExecuteEPNS_6ThreadERKNS_20CodeItemDataAccessorERNS_11ShadowFrameENS_6JValueEb.llvm.2088410233+496)
2019-05-15 11:01:49.226 4396-4424/my.app.android A/vations.androi: java_vm_ext.cc:542] native: #74 pc 000000000025b9e8 /system/lib64/libart.so (art::interpreter::ArtInterpreterToInterpreterBridge(art::Thread*, art::CodeItemDataAccessor const&, art::ShadowFrame*, art::JValue*)+216)
2019-05-15 11:01:49.226 4396-4424/my.app.android A/vations.androi: java_vm_ext.cc:542] native: #75 pc 000000000027c350 /system/lib64/libart.so (bool art::interpreter::DoCall<false, false>(art::ArtMethod*, art::Thread*, art::ShadowFrame&, art::Instruction const*, unsigned short, art::JValue*)+920)
2019-05-15 11:01:49.226 4396-4424/my.app.android A/vations.androi: java_vm_ext.cc:542] native: #76 pc 000000000052c418 /system/lib64/libart.so (MterpInvokeVirtual+584)
2019-05-15 11:01:49.226 4396-4424/my.app.android A/vations.androi: java_vm_ext.cc:542] native: #77 pc 000000000054f114 /system/lib64/libart.so (ExecuteMterpImpl+14228)
2019-05-15 11:01:49.226 4396-4424/my.app.android A/vations.androi: java_vm_ext.cc:542] native: #78 pc 0000000000116442 /system/framework/boot.vdex (java.util.concurrent.ThreadPoolExecutor$Worker.run+4)
2019-05-15 11:01:49.226 4396-4424/my.app.android A/vations.androi: java_vm_ext.cc:542] native: #79 pc 0000000000255e68 /system/lib64/libart.so (_ZN3art11interpreterL7ExecuteEPNS_6ThreadERKNS_20CodeItemDataAccessorERNS_11ShadowFrameENS_6JValueEb.llvm.2088410233+496)
2019-05-15 11:01:49.226 4396-4424/my.app.android A/vations.androi: java_vm_ext.cc:542] native: #80 pc 000000000025b9e8 /system/lib64/libart.so (art::interpreter::ArtInterpreterToInterpreterBridge(art::Thread*, art::CodeItemDataAccessor const&, art::ShadowFrame*, art::JValue*)+216)
2019-05-15 11:01:49.226 4396-4424/my.app.android A/vations.androi: java_vm_ext.cc:542] native: #81 pc 000000000027c350 /system/lib64/libart.so (bool art::interpreter::DoCall<false, false>(art::ArtMethod*, art::Thread*, art::ShadowFrame&, art::Instruction const*, unsigned short, art::JValue*)+920)
2019-05-15 11:01:49.226 4396-4424/my.app.android A/vations.androi: java_vm_ext.cc:542] native: #82 pc 000000000052d390 /system/lib64/libart.so (MterpInvokeInterface+1392)
2019-05-15 11:01:49.226 4396-4424/my.app.android A/vations.androi: java_vm_ext.cc:542] native: #83 pc 000000000054f314 /system/lib64/libart.so (ExecuteMterpImpl+14740)
2019-05-15 11:01:49.226 4396-4424/my.app.android A/vations.androi: java_vm_ext.cc:542] native: #84 pc 00000000000ca806 /system/framework/boot.vdex (java.lang.Thread.run+12)
2019-05-15 11:01:49.226 4396-4424/my.app.android A/vations.androi: java_vm_ext.cc:542] native: #85 pc 0000000000255e68 /system/lib64/libart.so (_ZN3art11interpreterL7ExecuteEPNS_6ThreadERKNS_20CodeItemDataAccessorERNS_11ShadowFrameENS_6JValueEb.llvm.2088410233+496)
2019-05-15 11:01:49.226 4396-4424/my.app.android A/vations.androi: java_vm_ext.cc:542] native: #86 pc 000000000051cb58 /system/lib64/libart.so (artQuickToInterpreterBridge+1032)
2019-05-15 11:01:49.226 4396-4424/my.app.android A/vations.androi: java_vm_ext.cc:542] native: #87 pc 0000000000565cfc /system/lib64/libart.so (art_quick_to_interpreter_bridge+92)
2019-05-15 11:01:49.226 4396-4424/my.app.android A/vations.androi: java_vm_ext.cc:542] native: #88 pc 000000000055cb88 /system/lib64/libart.so (art_quick_invoke_stub+584)
2019-05-15 11:01:49.226 4396-4424/my.app.android A/vations.androi: java_vm_ext.cc:542] native: #89 pc 00000000000cf740 /system/lib64/libart.so (art::ArtMethod::Invoke(art::Thread*, unsigned int*, unsigned int, art::JValue*, char const*)+200)
2019-05-15 11:01:49.226 4396-4424/my.app.android A/vations.androi: java_vm_ext.cc:542] native: #90 pc 00000000004633b8 /system/lib64/libart.so (art::(anonymous namespace)::InvokeWithArgArray(art::ScopedObjectAccessAlreadyRunnable const&, art::ArtMethod*, art::(anonymous namespace)::ArgArray*, art::JValue*, char const*)+104)
2019-05-15 11:01:49.226 4396-4424/my.app.android A/vations.androi: java_vm_ext.cc:542] native: #91 pc 0000000000464480 /system/lib64/libart.so (art::InvokeVirtualOrInterfaceWithJValues(art::ScopedObjectAccessAlreadyRunnable const&, _jobject*, _jmethodID*, jvalue*)+424)
2019-05-15 11:01:49.226 4396-4424/my.app.android A/vations.androi: java_vm_ext.cc:542] native: #92 pc 000000000048f830 /system/lib64/libart.so (art::Thread::CreateCallback(void*)+1120)
2019-05-15 11:01:49.226 4396-4424/my.app.android A/vations.androi: java_vm_ext.cc:542] native: #93 pc 0000000000083114 /system/lib64/libc.so (__pthread_start(void*)+36)
2019-05-15 11:01:49.226 4396-4424/my.app.android A/vations.androi: java_vm_ext.cc:542] native: #94 pc 00000000000233bc /system/lib64/libc.so (__start_thread+68)
2019-05-15 11:01:49.226 4396-4424/my.app.android A/vations.androi: java_vm_ext.cc:542] at com.couchbase.litecore.C4Replicator.free(Native method)
2019-05-15 11:01:49.226 4396-4424/my.app.android A/vations.androi: java_vm_ext.cc:542] at com.couchbase.litecore.C4Replicator.free(C4Replicator.java:126)
2019-05-15 11:01:49.226 4396-4424/my.app.android A/vations.androi: java_vm_ext.cc:542] at com.couchbase.lite.AbstractReplicator.clearRepl(AbstractReplicator.java:869)
2019-05-15 11:01:49.226 4396-4424/my.app.android A/vations.androi: java_vm_ext.cc:542] at com.couchbase.lite.AbstractReplicator.handleError(AbstractReplicator.java:800)
2019-05-15 11:01:49.226 4396-4424/my.app.android A/vations.androi: java_vm_ext.cc:542] at com.couchbase.lite.AbstractReplicator.c4StatusChanged(AbstractReplicator.java:756)
2019-05-15 11:01:49.226 4396-4424/my.app.android A/vations.androi: java_vm_ext.cc:542] - locked <0x0dac36c2> (a java.lang.Object)
2019-05-15 11:01:49.226 4396-4424/my.app.android A/vations.androi: java_vm_ext.cc:542] at com.couchbase.lite.AbstractReplicator.access$500(AbstractReplicator.java:74)
2019-05-15 11:01:49.226 4396-4424/my.app.android A/vations.androi: java_vm_ext.cc:542] at com.couchbase.lite.AbstractReplicator$4$1.run(AbstractReplicator.java:641)
2019-05-15 11:01:49.226 4396-4424/my.app.android A/vations.androi: java_vm_ext.cc:542] at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:458)
2019-05-15 11:01:49.226 4396-4424/my.app.android A/vations.androi: java_vm_ext.cc:542] at java.util.concurrent.FutureTask.run(FutureTask.java:266)
2019-05-15 11:01:49.226 4396-4424/my.app.android A/vations.androi: java_vm_ext.cc:542] at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:301)
2019-05-15 11:01:49.226 4396-4424/my.app.android A/vations.androi: java_vm_ext.cc:542] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1167)
2019-05-15 11:01:49.226 4396-4424/my.app.android A/vations.androi: java_vm_ext.cc:542] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:641)
2019-05-15 11:01:49.226 4396-4424/my.app.android A/vations.androi: java_vm_ext.cc:542] at java.lang.Thread.run(Thread.java:764)
2019-05-15 11:01:49.226 4396-4424/my.app.android A/vations.androi: java_vm_ext.cc:542]
Any news or something I can help you with?
Moving this issue to the repo for the couchbase-lite-android-ce product, here. Please follow it in the new location.
After some analysis, I think that there are multiple bugs here. I do not think that the crashes for any two of the logs shown here, were caused by the same underlying problem.
I've just made a substantial effort to clean up and bullet-proof the code for the Replicator in commits to couchbase-lite-java
(caa5b1ebf32c, 474434a80651, d3391886463f)
I've had a hard time actually driving this problem, so if any of you were willing to give it a try and report back, I'd very much appreciate it.
With no feedback, I am closing this issue.
After some analysis, I think that there are multiple bugs here. I do not think that the crashes for any two of the logs shown here, were caused by the same underlying problem. I've just made a substantial effort to clean up and bullet-proof the code for the Replicator in commits to
couchbase-lite-java
(caa5b1ebf32c, 474434a80651, d3391886463f) I've had a hard time actually driving this problem, so if any of you were willing to give it a try and report back, I'd very much appreciate it.
I've built from sources library and using couchbase-lite-android-2.7.0-SNAPSHOT-release.aar couchbase-android-ce HEAD at commit: e066b37 couchbase-android-core HEAD at commit: couchbase/couchbase-lite-core@2290bce
Confirming that this crash is not happening anymore.
Awesome @bpolanec ! Great news. Thanks for confirming.
For us, it has to do with SyncGateway config. We are running SG 2.x and CB Server 5.x which requires 'use_view' to be set true.
Crash in : com.couchbase.lite:couchbase-lite-android:2.5.0
after continuous replicators work for a while crash happens. I can reproduce it every time.
Log: