1.ANR介紹
1.1 何為ANR
ANR全名Application Not Responding, 也就是"應用無響應". 當操作在一段時間內系統無法處理時, 系統層面會彈出上圖那樣的ANR對話框.
1.2 為什么會產生ANR
Android里, App的響應能力是由Activity Manager和Window Manager系統服務來監控的. 通常在如下兩種情況下會彈出ANR對話框:
1：KeyDispatchTimeout(谷歌default 5s，MTK平台上是8s) --主要類型
按鍵或觸摸事件在特定時間內無響應
2：BroadcastTimeout(10s)
BroadcastReceiver在特定時間內無法處理完成
3：ServiceTimeout(20s) --小概率類型
Service在特定的時間內無法處理完成
1.3 如何避免ANR
知道了ANR產生的原因, 那么想要避免ANR, 也就很簡單了, 就一條規則:不要在主線程(UI線程)里面做繁重的操作
2.ANR的分析
將基於MTK平台討論ANR的一般解決思路，旨在通過了解本文后能夠對ANR問題能夠快速定位，減少排查的時間。
最好使用userdebug版本測試，因為ENG版本測試的話本身會加重CPU loading
獲取日志還有一點需要注意，發生ANR后，不要選擇結束進程，因為這樣AMS會kill掉該進程，有些信息會打印不出來，最好是ANR發生后等兩三分鍾左右，再將mtklog收集起來（db.XX.ANR寫入到aee_exp文件夾下需要時間）。這里的aee_exp文件夾一般都是需要的, 對DB進行dump解析，得到ANR發生時場景信息，比如主線程callstack，CPU，memory等，在分析問題根因時很關鍵。
日志分析一般步驟
Step1:
查看mobilelog文件夾下的events_log,搜索關鍵字"am_anr",這一步用於確認ANR時間點，可以搜索到類似如下信息
11-09 21:33:21.518: I/am_anr(1041): [0,1848,com.android.contacts,953728589,Input dispatching timed out (Waiting to send key event because the focused window has not finished processing all of the input events that were previously delivered to it. Outbound queue length: 0. Wait queue length: 1.)]
這個例子中的ANR類型為Input dispatching timed out, 這種anr的原因的是在viewrootimpl分發事件時，並沒有找到focuswindow導致的。時間點:21:33:21,進程號:1848 注意這里的進程號比較重要，后面要去trace.txt或者db文件中去看這個process(1848)對應的backtrace
Step2:
查看mobilelog文件夾下的main_log,搜索關鍵字"Application is not responding",發生ANR的時間或DB(MTK工具GAT)解析的_exp_main.txt
Backtrace:
Process: com.android.contacts
Flags: 0x38d8be4d
Package: com.android.contacts v24 (1.2)
Foreground: Yes
Activity: com.android.contacts/com.mediatek.contacts.list.ContactListMultiChoiceActivity
Subject: Input dispatching timed out (Waiting to send key event because the focused window has not finished processing all of the input events that were previously delivered to it. Outbound queue length: 0. Wait queue length: 1.)
Build: D-171117V33:user/release-keys
nullAndroid time :[2017-11-19 03:31:26.86] [107321.313]
ANR期間的 Cpu usage，前幾個占用情況以及Total如下：
CPU usage from 74494ms to 0ms ago (2019-11-09 21:32:06.966 to 2019-11-09 21:33:21.460):
104% 323/mobile_log_d: 17% user + 86% kernel / faults: 2622 minor
56% 1041/system_server: 41% user + 14% kernel / faults: 30698 minor 36 major
34% 1408/com.android.phone: 28% user + 6% kernel / faults: 17027 minor 35 major
15% 5541/android.process.acore: 13% user + 2.3% kernel / faults: 10865 minor 49 major
10% 248/servicemanager: 4.4% user + 6.5% kernel / faults: 63 minor
10% 249/surfaceflinger: 5.1% user + 5.6% kernel / faults: 1645 minor 1 major
8.6% 215/logd: 2.7% user + 5.8% kernel / faults: 310 minor 11 major
5.6% 1848/com.android.contacts: 4.4% user + 1.1% kernel / faults: 9569 minor 677 major
3.7% 1155/com.android.systemui: 2.9% user + 0.7% kernel / faults: 12145 minor 50 major
98% TOTAL: 54% user + 42% kernel + 0.1% iowait + 0% softirq
很多時候需要注意iowait的占有率，如果占比比較高，則排查的方向要傾向與讀取文件操作有關的信息，可以看trace日志中有沒有讀取文件或者操作SD卡的動作
還有注意觀察一下在出現“Application is not responding”信息往上看，注意主線程是不是有耗時的動作，可以搜索關鍵字"ActivityThread"且搜索到的片段含有ANR的進程名。
如果發現ANR時CPUloading並不高，再去檢查memory的情況，以排查是否存在競爭memory的情況。aee_exp文件下的db文件解析后會有一個 SYS_MEMORY_INFO文件，這個文件會列出問題發生時的MemTotal,MemFree,MemAvailable等信息。
Step3:
查看時間段內對應線程的 call stack
----- pid 1848 at 2019-11-09 21:33:21 -----
Cmd line: com.android.contacts
Build fingerprint: 'TECNO/H3721A1/TECNO-IN5:7.0/NRD90M/A-171108V56:user/release-keys'
ABI: 'arm64'
Build type: optimized
Zygote loaded classes=4375 post zygote classes=1641
Intern table: 50890 strong; 232 weak
JNI: CheckJNI is off; globals=848 (plus 2739 weak)
Libraries: /system/lib64/libandroid.so /system/lib64/libcompiler_rt.so /system/lib64/libdcfdecoderjni.so /system/lib64/libjavacrypto.so /system/lib64/libjnigraphics.so /system/lib64/libmedia_jni.so /system/lib64/libwebviewchromium_loader.so libjavacore.so libopenjdk.so (9)
Heap: 6% free, 35MB/37MB; 294645 objects
Dumping cumulative Gc timings
"main" prio=5 tid=1 Native
| group="main" sCount=1 dsCount=0 obj=0x75740b50 self=0x7128096a00
| sysTid=1848 nice=0 cgrp=default sched=0/0 handle=0x712c693a98
| state=S schedstat=( 343191137004 166931064193 540669 ) utm=28155 stm=6164 core=0 HZ=100
| stack=0x7fdc4ca000-0x7fdc4cc000 stackSize=8MB
| held mutexes=
at android.os.BinderProxy.transactNative(Native method)
at android.os.BinderProxy.transact(Binder.java:622)
at android.database.BulkCursorProxy.getWindow(BulkCursorNative.java:163)
at android.database.BulkCursorToCursorAdaptor.onMove(BulkCursorToCursorAdaptor.java:82)
at android.database.AbstractCursor.moveToPosition(AbstractCursor.java:236)
at android.database.CursorWrapper.moveToPosition(CursorWrapper.java:197)
at com.android.common.widget.CompositeCursorAdapter.getItem(CompositeCursorAdapter.java:436)
at com.mediatek.contacts.list.MultiPhoneAndEmailsPickerAdapter.getDataId(MultiPhoneAndEmailsPickerAdapter.java:230)
at com.mediatek.contacts.list.DataKindPickerBaseAdapter.getItemId(DataKindPickerBaseAdapter.java:249)
at android.widget.HeaderViewListAdapter.getItemId(HeaderViewListAdapter.java:194)
at android.widget.AdapterView.rememberSyncState(AdapterView.java:1255)
at android.widget.AbsListView.setItemChecked(AbsListView.java:1142)
at com.mediatek.contacts.list.AbstractPickerFragment.updateCheckBoxState(AbstractPickerFragment.java:742)
at com.mediatek.contacts.list.AbstractPickerFragment.onSelectAll(AbstractPickerFragment.java:261)
at com.mediatek.contacts.list.ContactListMultiChoiceActivity$1.onClick(ContactListMultiChoiceActivity.java:383)
at android.view.View.performClick(View.java:6076)
at android.widget.CompoundButton.performClick(CompoundButton.java:122)
at android.view.View$PerformClick.run(View.java:23138)
at android.os.Handler.handleCallback(Handler.java:836)
at android.os.Handler.dispatchMessage(Handler.java:103)
at android.os.Looper.loop(Looper.java:203)
at android.app.ActivityThread.main(ActivityThread.java:6292)
at java.lang.reflect.Method.invoke!(Native method)
at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:1094)
at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:955)
可以看到在等待binder返回
Step4:
binder分析 binder_analysis
[Info]: Start parse executing & pending transactions for 1848!
incoming transaction 118494543: 0000000000000000 from 1848:1848 to 5541:5554 code 1 flags 10 pri 0 r1 node 118458515 size 68:0 data 0000000000000000
[Analysis]: This binder call is waiting for 5541:5554 to executing complete.
outgoing transaction 118494543: 0000000000000000 from 1848:1848 to 5541:5554 code 1 flags 10 pri 0 r1 node 118458515 size 68:0 data 0000000000000000
[Analysis]: This binder call is waiting for 5541:5554 to executing complete.
pending transaction 118494731: 0000000000000000 from 0:0 to 1041:3702 code 0 flags 0 pri 0 r0 size 8:0 data 0000000000000000
[Analysis]: This binder call is waiting for 1041:3702 to executing complete.
查看SYS_PROCESSES_AND_THREADS 線程的信息
對端1041(system_server):3702(1041_D)
"Binder:1041_D" prio=5 tid=61 Native
| group="main" sCount=1 dsCount=0 obj=0x14b0c160 self=0x7110f02200
| sysTid=3702 nice=0 cgrp=default sched=0/0 handle=0x71078e1450
| state=S schedstat=( 775971117390 490089600857 2178398 ) utm=57038 stm=20559 core=2 HZ=100
| stack=0x71077e7000-0x71077e9000 stackSize=1005KB
| held mutexes=
kernel: (couldn't read /proc/self/task/3702/stack)
native: #00 pc 000000000001bcec /system/lib64/libc.so (syscall+28)
native: #01 pc 00000000000e77c8 /system/lib64/libart.so (_ZN3art17ConditionVariable16WaitHoldingLocksEPNS_6ThreadE+156)
native: #02 pc 000000000054aaac /system/lib64/libart.so (_ZN3artL12GoToRunnableEPNS_6ThreadE+328)
native: #03 pc 000000000054a920 /system/lib64/libart.so (_ZN3art12JniMethodEndEjPNS_6ThreadE+28)
native: #04 pc 000000000088b6a0 /system/framework/arm64/boot-framework.oat (Java_android_os_BinderProxy_transactNative__ILandroid_os_Parcel_2Landroid_os_Parcel_2I+220)
at android.os.BinderProxy.transactNative(Native method)
at android.os.BinderProxy.transact(Binder.java:622)
at android.os.ServiceManagerProxy.getService(ServiceManagerNative.java:123)
at android.os.ServiceManager.getService(ServiceManager.java:55)
at android.telephony.SubscriptionManager.getPhoneId(SubscriptionManager.java:1020)
at com.android.server.TelephonyRegistry.idMatch(TelephonyRegistry.java:1983)
at com.android.server.TelephonyRegistry.notifySignalStrengthForPhoneId(TelephonyRegistry.java:901)
- locked <0x0bb31bba> (a java.util.ArrayList)
at com.android.internal.telephony.ITelephonyRegistry$Stub.onTransact(ITelephonyRegistry.java:174)
at android.os.Binder.execTransact(Binder.java:570)
案例一：等待binder調用返回
SYS_BINDER_INFO這個文件查找當前這個線程在和誰通信
案例二：主線程等待鎖
主線程的CallStack DVM thread Status是Blocked
案例三：卡在IO上
這種情況一般是和文件操作相關，判斷是否是這種情況。IO占比很高，這個時候就需要查看trace日志看當時的callstack，着重看有沒有file相關的動作。
案例四：主線程作耗時的動作
耗時操作造成主線程堵塞
案例五：binder線程被占滿
系統對每個process最多分配15個binder線程，這個是谷歌的設計（/frameworks/native/libs/binder/ProcessState.cpp)
如果另一個process發送太多重復binder請求，那么就會導致接收端binder線程被占滿，從而處理不了其它的binder請求
這本身就是系統的一個限制，如果應用未按照系統的要求來實現對應邏輯，那么就會造成問題。
而系統端是不會（也不建議）通過修改系統行為來兼容應用邏輯，否則更容易造成其它根據系統需求正常編寫的應用反而出現不可預料的問題。
判斷Binder是否用完，可以在trace中搜索關鍵字"binder_f"，如果搜索到則表示已經用完，然后就要找log其他地方看是誰一直在消耗binder或者是有死鎖發生，對於binder用完的前期思路大致如此。
案例六：JE或者NE導致ANR
案例七：只存在於Monkey測試下
只在Monkey環境下才能跑出來，而user版本是不會出現的，這種問題沒有改動的意義。另外SAT
由於STK應用的特殊性，跑monkey會引發一些問題，如下為MTK的解釋：
[DESCRIPTION]
Monkey測試時，測試SAT會經常發生 ANR 或者phone進程掛掉的問題。有時雖然沒有跑到SAT中做測試，仍會因SAT應用導致許多異常現象。
[SOLUTION]
因為monkey測試時根本不適合跑SAT應用。主要是SAT應用涉及到卡跟手機或者卡跟網絡的交互，這些交互過程並無固定的時間長短，且都是需要耗費一定時間。
因此，monkey測試時如果包含或者跑SAT應用就很容易發生問題(比如很常見的ANR和一些其他問題)。
建議: 不同於其他 APP，不建議monkey測試包含 SAT 應用和測試SAT應用。
小結：
總的說來，拿到一份eng的完整日志，一般步驟如下：
1.find ANR time,PID,ANR type
2.check CPU usage and Memory
3.check trace.txt,mapping process ID and time stamp
4.find more information about main thread through main log and event log
附錄：
trace解析
該文檔我們主要說明trace的解析和一些客觀數據的如何獲取。
trace它是分析死機的非常重要的手段，我們可以快速的知道，對應的process/thread 在當時正在執行哪些動作，卡住哪里等。可以非常直觀的分析死機現場。
如果現場有問題機的話，我們還可以通過一些客觀的執行環境來分析，通常包括如CPU 利用率，Memory 使用情況， Storage 剩余情況等。這些資料也非常重要，比如可以快速的知道，當時是否有Process 在瘋狂的執行，當時是不是處於嚴重的low memory 情況， Storage 是否有耗盡的情況發生等。
我們知道出現問題java bt會在data/anr 保存相關的bt 信息，所以data/anr 里面的數據針對分析問題是很關鍵的，正常執行adb pull data/anr 我們都可以獲取一些比較完整的trace信息。下面是一小段system server 的java trace的開始，從第一行開始我們來按每一行解析其所代表的含義。
1，代表 PID at time
2，然后接着Cmd line: process name
3，固定頭，指明下面都是當前運行的dvm thread ，“DALVIK THREADS:” 及所包含的線程數 106
4，"main" prio=5 tid=1 Native
分別代表thread name, java thread Priority, DVM thread id, DVM thread status
"main" -> main thread -> activity thread
prio :java thread priority default is 5, （正常區域是1-10）
tid:是DVM thread id, 不是 linux thread id（下一行的sysTid才是）
Native:DVM thread Status 正常有這些狀態（ZOMBIE, RUNNABLE, TIMED_WAIT, MONITOR, WAIT, INITALIZING,STARTING, NATIVE, VMWAIT, SUSPENDED,UNKNOWN）
5，group="main" sCount=1 dsCount=0 obj=0x75720fb8 self=0x7f7e8af800
代表 DVM thread status。
group:是線程所處的線程組 default is “main”
sCount: 線程被正常掛起的次數 1 (thread suspend count)
dsCount: 線程因調試而掛起次數 0 (thread dbg suspend count)
obj: 當前線程所關聯的java線程對象 0x75720fb8 (thread obj address)
Sef: 該線程本身的地址 0x7f7e8af800 (thread point address)
6，sysTid=775 nice=-2 cgrp=default sched=0/0 handle=0x7f827d5e58
代表Linux thread status顯示線程調度信息
sysTId: linux系統下得本地線程id linux thread tid
Nice:線程的調度有優先級 linux thread nice value
cgrp: 優先組屬 c group
sched: 調度策略 cgroup policy/gourp id
handle: 處理函數地址 handle address
7，state=S schedstat=( 225588889412 17277569839 97525 ) utm=20901 stm=1657 core=3 HZ=100
代表CPU Sched stat 顯示更多該線程當前上下文
State:調度狀態 process/thread state （正常有 "R (running)", "S (sleeping)", "D (disk sleep)", "T (stopped)", "t (tracing stop)", "Z (zombie)", "X (dead)", "x (dead)", "K (wakekill)", "W (waking)",），通常一般的Process 處於的狀態都是S (sleeping), 而如果一旦發現處於如D (disk sleep), T (stopped), Z (zombie) 等就要認真審查.
Schedstat (Run CPU Clock/ns, Wait CPU Clock/ns, Slice times) 該線程運行信息
utm: utime, user space time 線程用戶態下使用的時間值(單位是jiffies）
stm: stime, kernel space time 內核態下得調度時間值
core: now running in cpu. 最后運行改線程的cup標識
8，stack=0x7f7dc93000-0x7f7dc95000 stackSize=1020KB
代表堆棧地址區域及size
9，held mutexes=
代表是否被鎖住，正常有四個屬性(mutexes: tll=0 tsl=0 tscl=0 ghl=0)，0表示unlock，其它值都代表被lock，
tll: thread List Lock,
tsl: thread Suspend Lock,
tscl: thread Suspend Count Lock
ghl: gc Heap Lock
10，剩余的就是一些 Call Stack
CPU Usage
追查CPU 利用率可大體的知道，當時機器是否有Process 在瘋狂的運行, 當時系統運行是否繁忙。通常死機分析，只需要抓取基本的使用情況即可。通常使用的命令如 top
top 可以簡單的查詢Cpu 的基本使用情況，注意的是top 的CPU% 是按全部CPU 來計算的，如果以單線程來計算，比如當時有開啟4個核心，那么最多吃到25%.
Memory Usage
我們通常會審查，系統當時memory 是否足夠, 是否處於low memory 狀態, 是否可能出現因無法申請到memory 而卡死的情況. 常見的一些基本信息如下:
* meminfo: basic memory status
adb shell cat proc/meminfo
adb shell cat proc/pid/maps
adb shell cat proc/pid/smaps
* procrank info: all process memory status
adb shell procrank
adb shell procmem pid
adb shell dumpsys meminfo pid
adb shell cat proc
adb shell cat /proc/buddyinfo
Storage Usage
查看Storage 的情況，通常主要是查詢data 分區是否已經刷滿, sdcard 是否已經刷滿, 剩余的空間是否足夠。以及是否有產生超大文件等。 通常使用的命令如 df
from: https://blog.csdn.net/sinat_34157462/java/article/details/78651870