4ntoine
Reputation: 20422
UsbDeviceConnection.requestWait() crashes in native code
I have an Android app which works with USB devices connected to Android device. I have a [pretty random] crash which comes from Android native code - when Java's UsbDeviceConnection.requestWait() is called it crashes natively inside:
2021-01-03 23:37:33.879 8307-11330 A/d.myusbapp: runtime.cc:630] Runtime aborting...
2021-01-03 23:37:33.879 8307-11330 A/d.myusbapp: runtime.cc:630] All threads:
2021-01-03 23:37:33.879 8307-11330 A/d.myusbapp: runtime.cc:630] DALVIK THREADS (90):
2021-01-03 23:37:33.879 8307-11330 A/d.myusbapp: runtime.cc:630] "Thread-33" prio=10 tid=28 Runnable
2021-01-03 23:37:33.879 8307-11330 A/d.myusbapp: runtime.cc:630] | group="" sCount=0 dsCount=0 flags=0 obj=0x12d74aa8 self=0x665ce400
2021-01-03 23:37:33.879 8307-11330 A/d.myusbapp: runtime.cc:630] | sysTid=11330 nice=-20 cgrp=default sched=0/0 handle=0x65522230
2021-01-03 23:37:33.879 8307-11330 A/d.myusbapp: runtime.cc:630] | state=R schedstat=( 24674013 1199219 14 ) utm=1 stm=1 core=7 HZ=100
2021-01-03 23:37:33.879 8307-11330 A/d.myusbapp: runtime.cc:630] | stack=0x6541f000-0x65421000 stackSize=1040KB
2021-01-03 23:37:33.879 8307-11330 A/d.myusbapp: runtime.cc:630] | held mutexes= "abort lock" "mutator lock"(shared held)
2021-01-03 23:37:33.879 8307-11330 A/d.myusbapp: runtime.cc:630] native: #00 pc 0030374f /apex/com.android.runtime/lib/libart.so (art::DumpNativeStack(std::__1::basic_ostream<char, std::__1::char_traits<char>>&, int, BacktraceMap*, char const*, art::ArtMethod*, void*, bool)+78)
2021-01-03 23:37:33.879 8307-11330 A/d.myusbapp: runtime.cc:630] native: #01 pc 003ae49f /apex/com.android.runtime/lib/libart.so (art::Thread::DumpStack(std::__1::basic_ostream<char, std::__1::char_traits<char>>&, bool, BacktraceMap*, bool) const+362)
2021-01-03 23:37:33.879 8307-11330 A/d.myusbapp: runtime.cc:630] native: #02 pc 003aac53 /apex/com.android.runtime/lib/libart.so (art::Thread::Dump(std::__1::basic_ostream<char, std::__1::char_traits<char>>&, bool, BacktraceMap*, bool) const+34)
2021-01-03 23:37:33.879 8307-11330 A/d.myusbapp: runtime.cc:630] native: #03 pc 003c3789 /apex/com.android.runtime/lib/libart.so (art::DumpCheckpoint::Run(art::Thread*)+588)
2021-01-03 23:37:33.879 8307-11330 A/d.myusbapp: runtime.cc:630] native: #04 pc 003bdf0d /apex/com.android.runtime/lib/libart.so (art::ThreadList::RunCheckpoint(art::Closure*, art::Closure*)+296)
2021-01-03 23:37:33.879 8307-11330 A/d.myusbapp: runtime.cc:630] native: #05 pc 003bd4b3 /apex/com.android.runtime/lib/libart.so (art::ThreadList::Dump(std::__1::basic_ostream<char, std::__1::char_traits<char>>&, bool)+1018)
2021-01-03 23:37:33.879 8307-11330 A/d.myusbapp: runtime.cc:630] native: #06 pc 0037d82b /apex/com.android.runtime/lib/libart.so (art::Runtime::Abort(char const*)+1054)
2021-01-03 23:37:33.879 8307-11330 A/d.myusbapp: runtime.cc:630] native: #07 pc 000084dd /system/lib/libbase.so (android::base::LogMessage::~LogMessage()+392)
2021-01-03 23:37:33.879 8307-11330 A/d.myusbapp: runtime.cc:630] native: #08 pc 001e0cf9 /apex/com.android.runtime/lib/libart.so (art::IndirectReferenceTable::AbortIfNoCheckJNI(std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char>> const&)+168)
2021-01-03 23:37:33.879 8307-11330 A/d.myusbapp: runtime.cc:630] native: #09 pc 00291367 /apex/com.android.runtime/lib/libart.so (art::IndirectReferenceTable::GetChecked(void*) const+278)
2021-01-03 23:37:33.879 8307-11330 A/d.myusbapp: runtime.cc:630] native: #10 pc 0028d9b1 /apex/com.android.runtime/lib/libart.so (art::JavaVMExt::DecodeGlobal(void*)+8)
2021-01-03 23:37:33.879 8307-11330 A/d.myusbapp: runtime.cc:630] native: #11 pc 003b2e13 /apex/com.android.runtime/lib/libart.so (art::Thread::DecodeJObject(_jobject*) const+170)
2021-01-03 23:37:33.879 8307-11330 A/d.myusbapp: runtime.cc:630] native: #12 pc 0041edbd /apex/com.android.runtime/lib/libart.so (_ZN3artL37JniMethodEndWithReferenceHandleResultEP8_jobjectjPNS_6ThreadE.llvm.4528425886332199447+36)
2021-01-03 23:37:33.879 8307-11330 A/d.myusbapp: runtime.cc:630] at android.hardware.usb.UsbDeviceConnection.native_request_wait(Native method)
2021-01-03 23:37:33.879 8307-11330 A/d.myusbapp: runtime.cc:630] at android.hardware.usb.UsbDeviceConnection.requestWait(UsbDeviceConnection.java:303)
2021-01-03 23:37:33.879 8307-11330 A/d.myusbapp: runtime.cc:630] at b.d.a.i.d.a.d$a.run(UartCh34x.java:7)
2021-01-03 23:37:33.879 8307-11330 A/d.myusbapp: runtime.cc:630] at java.lang.Thread.run(Thread.java:919)
Just before this i have a log message:
2021-01-03 23:37:32.808 8307-11330 A/d.myusbapp: indirect_reference_table.cc:60] JNI ERROR (app bug): attempt to use stale Global 0x3436 (should be 0x343a)
Next i have a full call stack:
--------- beginning of crash
2021-01-03 23:37:35.921 8307-11330 A/libc: Fatal signal 6 (SIGABRT), code -6 (SI_TKILL) in tid 11330 (Thread-33), pid 8307 (d.myusbapp)
2021-01-03 23:37:36.056 11339-11339 I/crash_dump32: obtaining output fd from tombstoned, type: kDebuggerdTombstone
2021-01-03 23:37:36.077 851-851 I//system/bin/tombstoned: received crash request for pid 11330
2021-01-03 23:37:36.080 11339-11339 I/crash_dump32: performing dump of process 8307 (target tid = 11330)
2021-01-03 23:37:36.112 11339-11339 A/DEBUG: *** *** *** *** *** *** *** *** *** *** *** *** *** *** *** ***
2021-01-03 23:37:36.112 11339-11339 A/DEBUG: Build fingerprint: 'Xiaomi/pine_ru/pine:10/QKQ1.191014.001/V11.0.3.0.QCMRUXM:user/release-keys'
2021-01-03 23:37:36.112 11339-11339 A/DEBUG: Revision: '0'
2021-01-03 23:37:36.112 11339-11339 A/DEBUG: ABI: 'arm'
2021-01-03 23:37:36.113 11339-11339 A/DEBUG: Timestamp: 2021-01-03 23:37:36+0500
2021-01-03 23:37:36.113 11339-11339 A/DEBUG: pid: 8307, tid: 11330, name: Thread-33 >>> com.company.project.myusbapp <<<
2021-01-03 23:37:36.113 11339-11339 A/DEBUG: uid: 10213
2021-01-03 23:37:36.113 11339-11339 A/DEBUG: signal 6 (SIGABRT), code -6 (SI_TKILL), fault addr --------
2021-01-03 23:37:36.113 11339-11339 A/DEBUG: Abort message: 'JNI ERROR (app bug): attempt to use stale Global 0x3436 (should be 0x343a)'
2021-01-03 23:37:36.113 11339-11339 A/DEBUG: r0 00000000 r1 00002c42 r2 00000006 r3 65521680
2021-01-03 23:37:36.113 11339-11339 A/DEBUG: r4 65521694 r5 65521678 r6 00002073 r7 0000016b
2021-01-03 23:37:36.113 11339-11339 A/DEBUG: r8 65521690 r9 65521680 r10 655216b0 r11 655216a0
2021-01-03 23:37:36.113 11339-11339 A/DEBUG: ip 00002c42 sp 65521650 lr aa08bd17 pc aa08bd2a
2021-01-03 23:37:36.846 1846-2340 D/MobileSignalController: onSignalStrengthsChanged: SignalStrength:{mCdma=CellSignalStrengthCdma: cdmaDbm=2147483647 cdmaEcio=2147483647 evdoDbm=2147483647 evdoEcio=2147483647 evdoSnr=2147483647 miuiLevel=0 level=0,mGsm=CellSignalStrengthGsm: rssi=2147483647 ber=2147483647 mTa=2147483647 miuiLevel=0 mLevel=0,mWcdma=CellSignalStrengthWcdma: ss=2147483647 ber=2147483647 rscp=2147483647 ecno=2147483647 miuiLevel=0 level=0,mTdscdma=CellSignalStrengthTdscdma: rssi=2147483647 ber=2147483647 rscp=2147483647 miuiLevel=0 level=0,mLte=CellSignalStrengthLte: rssi=-73 rsrp=-104 rsrq=-14 rssnr=52 cqi=2147483647 ta=2147483647 miuiLevel=4 level=3,mNr=CellSignalStrengthNr:{ csiRsrp = 2147483647 csiRsrq = 2147483647 csiSinr = 2147483647 ssRsrp = 2147483647 ssRsrq = 2147483647 ssSinr = 2147483647 miuiLevel = 0 level = 0 },primary=CellSignalStrengthLte}
2021-01-03 23:37:36.847 1846-2340 D/NetworkController.MobileSignalController(1): 4G level = 4
2021-01-03 23:37:36.876 11339-11339 A/DEBUG: backtrace:
2021-01-03 23:37:36.876 11339-11339 A/DEBUG: #00 pc 0005ed2a /apex/com.android.runtime/lib/bionic/libc.so (abort+166) (BuildId: 36720ba5aeb300d75235d367cb8550ae)
2021-01-03 23:37:36.876 11339-11339 A/DEBUG: #01 pc 0037daa1 /apex/com.android.runtime/lib/libart.so (art::Runtime::Abort(char const*)+1684) (BuildId: 3afb877429edc5fab166cfea8c7a1d7f)
2021-01-03 23:37:36.877 11339-11339 A/DEBUG: #02 pc 000084dd /system/lib/libbase.so (android::base::LogMessage::~LogMessage()+392) (BuildId: 7d8757d0af891f885311e79971c7fb33)
2021-01-03 23:37:36.877 11339-11339 A/DEBUG: #03 pc 001e0cf9 /apex/com.android.runtime/lib/libart.so (art::IndirectReferenceTable::AbortIfNoCheckJNI(std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char>> const&)+168) (BuildId: 3afb877429edc5fab166cfea8c7a1d7f)
2021-01-03 23:37:36.877 11339-11339 A/DEBUG: #04 pc 00291367 /apex/com.android.runtime/lib/libart.so (art::IndirectReferenceTable::GetChecked(void*) const+278) (BuildId: 3afb877429edc5fab166cfea8c7a1d7f)
2021-01-03 23:37:36.877 11339-11339 A/DEBUG: #05 pc 0028d9b1 /apex/com.android.runtime/lib/libart.so (art::JavaVMExt::DecodeGlobal(void*)+8) (BuildId: 3afb877429edc5fab166cfea8c7a1d7f)
2021-01-03 23:37:36.877 11339-11339 A/DEBUG: #06 pc 003b2e13 /apex/com.android.runtime/lib/libart.so (art::Thread::DecodeJObject(_jobject*) const+170) (BuildId: 3afb877429edc5fab166cfea8c7a1d7f)
2021-01-03 23:37:36.877 11339-11339 A/DEBUG: #07 pc 0041edbd /apex/com.android.runtime/lib/libart.so (_ZN3artL37JniMethodEndWithReferenceHandleResultEP8_jobjectjPNS_6ThreadE.llvm.4528425886332199447+36) (BuildId: 3afb877429edc5fab166cfea8c7a1d7f)
2021-01-03 23:37:36.877 11339-11339 A/DEBUG: #08 pc 00b81a4d /system/framework/arm/boot-framework.oat (art_jni_trampoline+92) (BuildId: f16c3d6eb53614bd493f23b001449977fca78529)
2021-01-03 23:37:36.877 11339-11339 A/DEBUG: #09 pc 00b8205b /system/framework/arm/boot-framework.oat (android.hardware.usb.UsbDeviceConnection.requestWait+50) (BuildId: f16c3d6eb53614bd493f23b001449977fca78529)
2021-01-03 23:37:36.877 11339-11339 A/DEBUG: #10 pc 000d7bc5 /apex/com.android.runtime/lib/libart.so (art_quick_invoke_stub_internal+68) (BuildId: 3afb877429edc5fab166cfea8c7a1d7f)
2021-01-03 23:37:36.877 11339-11339 A/DEBUG: #11 pc 00436235 /apex/com.android.runtime/lib/libart.so (art_quick_invoke_stub+252) (BuildId: 3afb877429edc5fab166cfea8c7a1d7f)
2021-01-03 23:37:36.877 11339-11339 A/DEBUG: #12 pc 000dffeb /apex/com.android.runtime/lib/libart.so (art::ArtMethod::Invoke(art::Thread*, unsigned int*, unsigned int, art::JValue*, char const*)+178) (BuildId: 3afb877429edc5fab166cfea8c7a1d7f)
2021-01-03 23:37:36.877 11339-11339 A/DEBUG: #13 pc 002136fd /apex/com.android.runtime/lib/libart.so (art::interpreter::ArtInterpreterToCompiledCodeBridge(art::Thread*, art::ArtMethod*, art::ShadowFrame*, unsigned short, art::JValue*)+280) (BuildId: 3afb877429edc5fab166cfea8c7a1d7f)
2021-01-03 23:37:36.877 11339-11339 A/DEBUG: #14 pc 0020f015 /apex/com.android.runtime/lib/libart.so (bool art::interpreter::DoCall<false, false>(art::ArtMethod*, art::Thread*, art::ShadowFrame&, art::Instruction const*, unsigned short, art::JValue*)+716) (BuildId: 3afb877429edc5fab166cfea8c7a1d7f)
2021-01-03 23:37:36.877 11339-11339 A/DEBUG: #15 pc 004309fd /apex/com.android.runtime/lib/libart.so (MterpInvokeVirtualQuick+544) (BuildId: 3afb877429edc5fab166cfea8c7a1d7f)
2021-01-03 23:37:36.877 11339-11339 A/DEBUG: #16 pc 000d6594 /apex/com.android.runtime/lib/libart.so (mterp_op_invoke_virtual_quick+20) (BuildId: 3afb877429edc5fab166cfea8c7a1d7f)
2021-01-03 23:37:36.877 11339-11339 A/DEBUG: #17 pc 00b3c5ec /data/app/com.company.project.myusbapp-qaSxE0kill2Jg9li_hI30A==/oat/arm/base.vdex (b.d.a.i.d.a.d$a.run+112)
2021-01-03 23:37:36.878 11339-11339 A/DEBUG: #18 pc 001eea01 /apex/com.android.runtime/lib/libart.so (_ZN3art11interpreterL7ExecuteEPNS_6ThreadERKNS_20CodeItemDataAccessorERNS_11ShadowFrameENS_6JValueEbb.llvm.6552526831605965956+192) (BuildId: 3afb877429edc5fab166cfea8c7a1d7f)
2021-01-03 23:37:36.878 11339-11339 A/DEBUG: #19 pc 001f31f3 /apex/com.android.runtime/lib/libart.so (art::interpreter::EnterInterpreterFromEntryPoint(art::Thread*, art::CodeItemDataAccessor const&, art::ShadowFrame*)+126) (BuildId: 3afb877429edc5fab166cfea8c7a1d7f)
2021-01-03 23:37:36.878 11339-11339 A/DEBUG: #20 pc 0041fd1d /apex/com.android.runtime/lib/libart.so (artQuickToInterpreterBridge+852) (BuildId: 3afb877429edc5fab166cfea8c7a1d7f)
2021-01-03 23:37:36.878 11339-11339 A/DEBUG: #21 pc 000dc5a1 /apex/com.android.runtime/lib/libart.so (art_quick_to_interpreter_bridge+32) (BuildId: 3afb877429edc5fab166cfea8c7a1d7f)
2021-01-03 23:37:36.878 11339-11339 A/DEBUG: #22 pc 00433469 /system/framework/arm/boot.oat (java.lang.Thread.run+64) (BuildId: 25dc848c49b73a592dfde9bbb8215f223aa6d205)
2021-01-03 23:37:36.878 11339-11339 A/DEBUG: #23 pc 000d7bc5 /apex/com.android.runtime/lib/libart.so (art_quick_invoke_stub_internal+68) (BuildId: 3afb877429edc5fab166cfea8c7a1d7f)
2021-01-03 23:37:36.878 11339-11339 A/DEBUG: #24 pc 00436235 /apex/com.android.runtime/lib/libart.so (art_quick_invoke_stub+252) (BuildId: 3afb877429edc5fab166cfea8c7a1d7f)
2021-01-03 23:37:36.878 11339-11339 A/DEBUG: #25 pc 000dffeb /apex/com.android.runtime/lib/libart.so (art::ArtMethod::Invoke(art::Thread*, unsigned int*, unsigned int, art::JValue*, char const*)+178) (BuildId: 3afb877429edc5fab166cfea8c7a1d7f)
2021-01-03 23:37:36.878 11339-11339 A/DEBUG: #26 pc 0037738b /apex/com.android.runtime/lib/libart.so (art::(anonymous namespace)::InvokeWithArgArray(art::ScopedObjectAccessAlreadyRunnable const&, art::ArtMethod*, art::(anonymous namespace)::ArgArray*, art::JValue*, char const*)+54) (BuildId: 3afb877429edc5fab166cfea8c7a1d7f)
2021-01-03 23:37:36.878 11339-11339 A/DEBUG: #27 pc 00378113 /apex/com.android.runtime/lib/libart.so (art::InvokeVirtualOrInterfaceWithJValues(art::ScopedObjectAccessAlreadyRunnable const&, _jobject*, _jmethodID*, jvalue const*)+306) (BuildId: 3afb877429edc5fab166cfea8c7a1d7f)
2021-01-03 23:37:36.878 11339-11339 A/DEBUG: #28 pc 003a924f /apex/com.android.runtime/lib/libart.so (art::Thread::CreateCallback(void*)+986) (BuildId: 3afb877429edc5fab166cfea8c7a1d7f)
2021-01-03 23:37:36.878 11339-11339 A/DEBUG: #29 pc 000a69c7 /apex/com.android.runtime/lib/bionic/libc.so (__pthread_start(void*)+20) (BuildId: 36720ba5aeb300d75235d367cb8550ae)
2021-01-03 23:37:36.878 11339-11339 A/DEBUG: #30 pc 000601bf /apex/com.android.runtime/lib/bionic/libc.so (__start_thread+30) (BuildId: 36720ba5aeb300d75235d367cb8550ae)
This is hard to reproduce intentionally and it happens on a different versions of Android. I was able to catch it once on Android 10, but i can see the reports from Firebase Crashlytics on different versions.
Any ideas on what's wrong? How can it be catched (since it happens in Android native code)?
PS. The app has few millions of installs and it works good in most of cases..
Upvotes: 0
Views: 448
Answers (1)
4ntoine
Reputation: 20422
It seems it's racy and can be inconsistent inside: avoid quick open/closing and keep in mind multithreading. I was able to fix it with just avoiding 2 consequent device open/read/close.
Upvotes: 0
Related Questions
- Android requestWait of usb serial is not blocking for FT232R device
- libusb_open_device_with_vid_pid failed when trying to access USB device
- UsbDeviceConnection requestWait() native crash
- UsbDeviceConnection bulktransfer not working properly
- What causes UsbRequest to throw IO Exception from queue method?
- UsbRequest.queue crashing Android 3.1 application
- Android USB to Serial Receive Error
- android read usb asynchronously
- android usb requestWait not return
- USB detection code for android device is crashing