Android ANR 分析

首先贴一下trace 文件

Process: com.oppo.readerPID: 20358Time: 2933175644_1545041895232Flags: 0x38d83e44Package: com.oppo.reader v62301 (6.2.3.20181030)PID: 20358Foreground: YesActivity: com.oppo.reader/com.zhangyue.iReader.read.ui.Activity_BookBrowser_TXTSubject: Input dispatching timed out (Waiting to send non-key event because the touched window has not finished processing certain input events that were delivered to it over 500.0ms ago.  Wait queue length: 2.  Wait queue head age: 8825.0ms.)Build: OPPO/PBFM00/PBFM00:8.1.0/OPM1.171019.026/1541766248:user/release-keysCPU usage from 0ms to 6451ms later (2018-12-17 18:18:08.726 to 2018-12-17 18:18:15.177):  100% 20358/com.oppo.reader: 97% user + 3.5% kernel / faults: 4111 minor 3 major  39% 1895/system_server: 27% user + 11% kernel / faults: 3126 minor 26 major  0.2% 1167/media.codec: 0.2% user + 0% kernel / faults: 4081 minor  4% 17827/com.android.systemui: 3.2% user + 0.7% kernel / faults: 1640 minor 224 major  3.7% 2835/com.android.phone: 3.2% user + 0.4% kernel / faults: 434 minor  3.4% 687/surfaceflinger: 2.4% user + 0.9% kernel / faults: 454 minor26% TOTAL: 20% user + 4.6% kernel + 0.5% iowait + 0.3% irq + 0.1% softirq----- pid 20358 at 2018-12-17 18:18:09 -----Cmd line: com.oppo.readerBuild fingerprint: 'OPPO/PBFM00/PBFM00:8.1.0/OPM1.171019.026/1541766248:user/release-keys'ABI: 'arm'Build type: optimizedZygote loaded classes=5110 post zygote classes=3166Intern table: 52731 strong; 145 weakJNI: CheckJNI is off; globals=727 (plus 79 weak)Libraries: /data/app/com.oppo.reader-NTuEuWlogpCo1aD9HtyDhQ==/lib/arm/libUiControl.so /data/app/com.oppo.reader-NTuEuWlogpCo1aD9HtyDhQ==/lib/arm/libtingReader.so /system/app/WebViewGoogleNX/WebViewGoogleNX.apk!/lib/armeabi-v7a/libwebviewchromium.so /system/lib/libandroid.so /system/lib/libcompiler_rt.so /system/lib/libjavacrypto.so /system/lib/libjnigraphics.so /system/lib/libmedia_jni.so /system/lib/libqti_performance.so /system/lib/libsoundpool.so /system/lib/libwebviewchromium_loader.so /system/lib/libwebviewchromium_plat_support.so libjavacore.so libopenjdk.so (14)Heap: 24% free, 16MB/22MB; 262809 objectsDumping cumulative Gc timingsStart Dumping histograms for 8 iterations for concurrent copyingProcessMarkStack:Sum: 430.463ms 99% C.I. 12.291ms-126.080ms Avg: 53.807ms Max: 127.672msProfileSaver total_ms_of_work=60ProfileSaver max_number_profile_entries_cached=0ProfileSaver total_number_of_hot_spikes=2ProfileSaver total_number_of_wake_ups=4Number of JIT inline cache deoptimizations: 2suspend all histogram:Sum: 1.234ms 99% C.I. 9us-160.399us Avg: 31.641us Max: 169usDALVIK THREADS (70):"Signal Catcher" daemon prio=5 tid=3 Runnable  | group="system" sCount=0 dsCount=0 flags=0 obj=0x13500280 self=0xe6c0fc00  | sysTid=20364 nice=0 cgrp=default sched=0/0 handle=0xdcbfe970  | state=R schedstat=( 27239057 2910573 19 ) utm=2 stm=0 core=0 HZ=100  | stack=0xdcb04000-0xdcb06000 stackSize=1006KB  | held mutexes= "mutator lock"(shared held)  native: #00 pc 002e8b57  /system/lib/libart.so (art::DumpNativeStack(std::__1::basic_ostream>&, int, BacktraceMap*, char const*, art::ArtMethod*, void*)+130)  native: #01 pc 0037b7f9  /system/lib/libart.so (art::Thread::DumpStack(std::__1::basic_ostream>&, bool, BacktraceMap*, bool) const+204)  native: #02 pc 00377d2b  /system/lib/libart.so (art::Thread::Dump(std::__1::basic_ostream>&, bool, BacktraceMap*, bool) const+34)  native: #03 pc 0038f8fb  /system/lib/libart.so (art::DumpCheckpoint::Run(art::Thread*)+698)  native: #04 pc 0038947d  /system/lib/libart.so (art::ThreadList::RunCheckpoint(art::Closure*, art::Closure*)+320)  native: #05 pc 00388f7b  /system/lib/libart.so (art::ThreadList::Dump(std::__1::basic_ostream>&, bool)+530)  native: #06 pc 00388c9b  /system/lib/libart.so (art::ThreadList::DumpForSigQuit(std::__1::basic_ostream>&)+626)  native: #07 pc 003652d3  /system/lib/libart.so (art::Runtime::DumpForSigQuit(std::__1::basic_ostream>&)+122)  native: #08 pc 0036d9b3  /system/lib/libart.so (art::SignalCatcher::HandleSigQuit()+1282)  native: #09 pc 0036c91b  /system/lib/libart.so (art::SignalCatcher::Run(void*)+330)  native: #10 pc 000473f3  /system/lib/libc.so (__pthread_start(void*)+22)  native: #11 pc 0001afb1  /system/lib/libc.so (__start_thread+32)  (no managed stack frames)"main" prio=5 tid=1 Blocked  | group="main" sCount=1 dsCount=0 flags=1 obj=0x71ebca68 self=0xe6c0f000  | sysTid=20358 nice=-10 cgrp=default sched=0/0 handle=0xea9254a4  | state=S schedstat=( 2882074832 469149273 2373 ) utm=241 stm=47 core=1 HZ=100  | stack=0xff789000-0xff78b000 stackSize=8MB  | held mutexes=  at com.zhangyue.iReader.DB.DBAdapter.execSQL(SourceFile:2512)  - waiting to lock <0x08d75003> (a com.zhangyue.iReader.DB.DBAdapter) held by thread 66  at com.zhangyue.iReader.DB.DBAdapter.queryBookIDWithoutPath(SourceFile:1497)  at com.zhangyue.iReader.read.ui.BookBrowserFragment.u(SourceFile:1223)  at com.zhangyue.iReader.read.ui.BookBrowserFragment.U(SourceFile:368)  at com.zhangyue.iReader.read.ui.cc.run(SourceFile:3098)  at android.os.Handler.handleCallback(Handler.java:790)  at android.os.Handler.dispatchMessage(Handler.java:99)  at android.os.Looper.loop(Looper.java:198)  at android.app.ActivityThread.main(ActivityThread.java:7038)  at java.lang.reflect.Method.invoke(Native method)  at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:519)  at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:836)"Jit thread pool worker thread 0" daemon prio=5 tid=2 Native  | group="main" sCount=1 dsCount=0 flags=1 obj=0x135001f8 self=0xdcd1f000  | sysTid=20363 nice=9 cgrp=default sched=0/0 handle=0xdccff970  | state=S schedstat=( 803558025 113797923 579 ) utm=76 stm=4 core=6 HZ=100  | stack=0xdcc01000-0xdcc03000 stackSize=1022KB  | held mutexes=  kernel: (couldn't read /proc/self/task/20363/stack)  native: #00 pc 00018e20  /system/lib/libc.so (syscall+28)  native: #01 pc 000b79d1  /system/lib/libart.so (art::ConditionVariable::WaitHoldingLocks(art::Thread*)+80)  native: #02 pc 00390b81  /system/lib/libart.so (art::ThreadPool::GetTask(art::Thread*)+172)  native: #03 pc 003904f7  /system/lib/libart.so (art::ThreadPoolWorker::Run()+62)  native: #04 pc 00390115  /system/lib/libart.so (art::ThreadPoolWorker::Callback(void*)+92)  native: #05 pc 000473f3  /system/lib/libc.so (__pthread_start(void*)+22)  native: #06 pc 0001afb1  /system/lib/libc.so (__start_thread+32)  (no managed stack frames)"ReferenceQueueDaemon" daemon prio=5 tid=4 Waiting  | group="system" sCount=1 dsCount=0 flags=1 obj=0x13500308 self=0xdca14600  | sysTid=20365 nice=4 cgrp=default sched=0/0 handle=0xc9e29970  | state=S schedstat=( 34968799 11582865 55 ) utm=2 stm=1 core=4 HZ=100  | stack=0xc9d27000-0xc9d29000 stackSize=1038KB  | held mutexes=  at java.lang.Object.wait(Native method)  - waiting on <0x03602b80> (a java.lang.Class)  at java.lang.Daemons$ReferenceQueueDaemon.runInternal(Daemons.java:183)  - locked <0x03602b80> (a java.lang.Class)  at java.lang.Daemons$Daemon.run(Daemons.java:108)  at java.lang.Thread.run(Thread.java:764)    "OkHttp https://icloud.zhangyue.com/..." prio=5 tid=66 Native  | group="main" sCount=1 dsCount=0 flags=1 obj=0x133c0a30 self=0xc4ca9200  | sysTid=21822 nice=0 cgrp=default sched=0/0 handle=0xbe396970  | state=S schedstat=( 14565089915 55131141 764 ) utm=1423 stm=33 core=2 HZ=100  | stack=0xbe294000-0xbe296000 stackSize=1038KB  | held mutexes=  kernel: (couldn't read /proc/self/task/21822/stack)  native: #00 pc 00018e20  /system/lib/libc.so (syscall+28)  native: #01 pc 000b79d1  /system/lib/libart.so (art::ConditionVariable::WaitHoldingLocks(art::Thread*)+80)  native: #02 pc 003e2949  /system/lib/libart.so (art::GoToRunnable(art::Thread*)+300)  native: #03 pc 003e27ed  /system/lib/libart.so (art::JniMethodEnd(unsigned int, art::Thread*)+8)  native: #04 pc 00404d45  /system/framework/arm/boot-framework.oat (Java_android_database_sqlite_SQLiteConnection_nativeExecuteForChangedRowCount__JJ+132)  at android.database.sqlite.SQLiteConnection.nativeExecuteForChangedRowCount(Native method)  at android.database.sqlite.SQLiteConnection.executeForChangedRowCount(SQLiteConnection.java:748)  at android.database.sqlite.SQLiteSession.executeForChangedRowCount(SQLiteSession.java:754)  at android.database.sqlite.SQLiteStatement.executeUpdateDelete(SQLiteStatement.java:64)  at android.database.sqlite.SQLiteDatabase.updateWithOnConflict(SQLiteDatabase.java:1658)  at android.database.sqlite.SQLiteDatabase.update(SQLiteDatabase.java:1604)  at com.zhangyue.iReader.DB.a.update(SourceFile:129)  at com.zhangyue.iReader.DB.DBAdapter.update(SourceFile:4224)  at dt.d.b(SourceFile:112)  at com.zhangyue.iReader.DB.DBAdapter.updateHighLightByPostion(SourceFile:1657)  at df.t.b(SourceFile:269)  - locked <0x08d75003> (a com.zhangyue.iReader.DB.DBAdapter)  at df.t.a(SourceFile:66)  at df.al.a(SourceFile:118)  at df.am.onHttpEvent(SourceFile:88)  at com.zhangyue.net.p$b.onHttpEvent(SourceFile:138)  at com.zhangyue.net.a.a(SourceFile:796)  at com.zhangyue.net.a.a(SourceFile:63)  at com.zhangyue.net.c.onResponse(SourceFile:698)  at okhttp3.RealCall$AsyncCall.execute(SourceFile:153)  at okhttp3.internal.NamedRunnable.run(SourceFile:32)  at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1162)  at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:636)  at java.lang.Thread.run(Thread.java:764)

开头会告诉你，是哪个包ANR 了。所以，以后搜索ANR 可以在log 里面搜索：

Cmd line: com.oppo.reader

后面替换成你的包名。

第一步：查看主线程

"main" prio=5 tid=1 Blocked  | group="main" sCount=1 dsCount=0 flags=1 obj=0x71ebca68 self=0xe6c0f000  | sysTid=20358 nice=-10 cgrp=default sched=0/0 handle=0xea9254a4  | state=S schedstat=( 2882074832 469149273 2373 ) utm=241 stm=47 core=1 HZ=100  | stack=0xff789000-0xff78b000 stackSize=8MB  | held mutexes=  at com.zhangyue.iReader.DB.DBAdapter.execSQL(SourceFile:2512)  - waiting to lock <0x08d75003> (a com.zhangyue.iReader.DB.DBAdapter) held by thread 66  at com.zhangyue.iReader.DB.DBAdapter.queryBookIDWithoutPath(SourceFile:1497)  at com.zhangyue.iReader.read.ui.BookBrowserFragment.u(SourceFile:1223)  at com.zhangyue.iReader.read.ui.BookBrowserFragment.U(SourceFile:368)  at com.zhangyue.iReader.read.ui.cc.run(SourceFile:3098)  at android.os.Handler.handleCallback(Handler.java:790)  at android.os.Handler.dispatchMessage(Handler.java:99)  at android.os.Looper.loop(Looper.java:198)  at android.app.ActivityThread.main(ActivityThread.java:7038)  at java.lang.reflect.Method.invoke(Native method)  at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:519)  at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:836)

- waiting to lock <0x08d75003> (a com.zhangyue.iReader.DB.DBAdapter) held by thread 66
他说，在等待一个锁，0x08d75003。你可以在trace 里面搜索这个字符，或者后面说，held by thread 66，那就搜索线程66

tid=66

第二步：找到线程66

  "OkHttp https://icloud.zhangyue.com/..." prio=5 tid=66 Native  | group="main" sCount=1 dsCount=0 flags=1 obj=0x133c0a30 self=0xc4ca9200  | sysTid=21822 nice=0 cgrp=default sched=0/0 handle=0xbe396970  | state=S schedstat=( 14565089915 55131141 764 ) utm=1423 stm=33 core=2 HZ=100  | stack=0xbe294000-0xbe296000 stackSize=1038KB  | held mutexes=  kernel: (couldn't read /proc/self/task/21822/stack)  native: #00 pc 00018e20  /system/lib/libc.so (syscall+28)  native: #01 pc 000b79d1  /system/lib/libart.so (art::ConditionVariable::WaitHoldingLocks(art::Thread*)+80)  native: #02 pc 003e2949  /system/lib/libart.so (art::GoToRunnable(art::Thread*)+300)  native: #03 pc 003e27ed  /system/lib/libart.so (art::JniMethodEnd(unsigned int, art::Thread*)+8)  native: #04 pc 00404d45  /system/framework/arm/boot-framework.oat (Java_android_database_sqlite_SQLiteConnection_nativeExecuteForChangedRowCount__JJ+132)  at android.database.sqlite.SQLiteConnection.nativeExecuteForChangedRowCount(Native method)  at android.database.sqlite.SQLiteConnection.executeForChangedRowCount(SQLiteConnection.java:748)  at android.database.sqlite.SQLiteSession.executeForChangedRowCount(SQLiteSession.java:754)  at android.database.sqlite.SQLiteStatement.executeUpdateDelete(SQLiteStatement.java:64)  at android.database.sqlite.SQLiteDatabase.updateWithOnConflict(SQLiteDatabase.java:1658)  at android.database.sqlite.SQLiteDatabase.update(SQLiteDatabase.java:1604)  at com.zhangyue.iReader.DB.a.update(SourceFile:129)  at com.zhangyue.iReader.DB.DBAdapter.update(SourceFile:4224)  at dt.d.b(SourceFile:112)  at com.zhangyue.iReader.DB.DBAdapter.updateHighLightByPostion(SourceFile:1657)  at df.t.b(SourceFile:269)  - locked <0x08d75003> (a com.zhangyue.iReader.DB.DBAdapter)  at df.t.a(SourceFile:66)  at df.al.a(SourceFile:118)  at df.am.onHttpEvent(SourceFile:88)  at com.zhangyue.net.p$b.onHttpEvent(SourceFile:138)  at com.zhangyue.net.a.a(SourceFile:796)  at com.zhangyue.net.a.a(SourceFile:63)  at com.zhangyue.net.c.onResponse(SourceFile:698)  at okhttp3.RealCall$AsyncCall.execute(SourceFile:153)  at okhttp3.internal.NamedRunnable.run(SourceFile:32)  at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1162)  at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:636)  at java.lang.Thread.run(Thread.java:764)

问下了同事， - locked <0x08d75003> (a com.zhangyue.iReader.DB.DBAdapter) 表示，从这行的堆栈开始，进入synchronized 代码块。（至于是不是，可以自己去获取堆栈，尝试下。）
那么，也就是在这里，子线程执行代码，占用了 - locked <0x08d75003> (a com.zhangyue.iReader.DB.DBAdapter)这个锁。

第三步：处理

怎么处理呢？

把没有用的锁，去掉。程序里面不要随意的加锁
我们这里是因为一大坨代码，都写在了执行事务里，导致，执行事务的时候，占用了SQLite 链接。导致主线程拿不到SQLite 的锁。

其他技巧

1.如果你觉得是某一块代码执行时间过长导致ANR,那么可以把这一块代码换成下面这个，看看会不会ANR.

        long begin  = System.currentTimeMillis();        while(System.currentTimeMillis() - begin < 1000 * 60 * 10){            a = 50;            DBAdapter.getInstance().queryALLBook();        }

上面这块代码，会执行10分钟。里面不停的执行SQL 操作。

首先贴一下trace 文件

第一步：查看主线程

第二步：找到线程66

第三步：处理

其他技巧

更多相关文章

随机推荐