1、 前言
在上一篇文章《Android效能優化(六)之卡頓那些事》中,我們提到了卡頓的成因、檢測卡頓的途徑以及避免卡頓的方法。卡頓在擴大就會產生大名鼎鼎的ANR(Application Not Responding),然後告訴使用者你的App無響應,繼續等待或者強制關閉,很大的概率使用者可能會順手解除安裝如此卡的App。
ANR造成的影響特別嚴重,而在實際開發過程中我們一般都會使用非同步來規避ANR,但同時也正因為此我們可能會對ANR熟視無睹:因為常見,所以多見不怪!不信我來提個問題:
- 在《Multidex(二)之 Dex 預載入優化》中採用單獨開程式執行Dex預載入優化的操作時,主程式在後臺sleep(),為什麼不會出現ANR呢?
2、 ANR分析
2.1 ANR的分類:
KeyDispatchTimeout –按鍵或觸控事件在特定時間內無響應;
BroadcastTimeout –BroadcastReceiver在特定時間內無法處理完成;
ServiceTimeout –Service在特定的時間內無法處理完成;
2.2 ANR的發生原因:
- 應用自身引起,例如:
- 主執行緒阻塞、IOWait等;
- 其他程式間接引起,例如:
- 當前應用程式進行程式間通訊請求其他程式,其他程式的操作長時間沒有反饋;
- 其他程式的CPU佔用率高,使得當前應用程式無法搶佔到CPU時間片;
2.3 ANR日誌分析:
當發生ANR的時候Logcat中會出現提示;
04-06 15:58:46.215 23480-23483/com.example.testanr I/art: Thread[2,tid=23483,WaitingInMainSignalCatcherLoop,Thread*=0x7fa2307000,peer=0x12cb40a0,"Signal Catcher"]: reacting to signal 3
04-06 15:58:46.364 23480-23483/com.example.testanr I/art: Wrote stack traces to '/data/anr/traces.txt'複製程式碼
ANR的Log資訊儲存在:/data/anr/traces.txt,每一次新的ANR發生,會把之前的ANR資訊覆蓋掉。
例如:
04-01 13:12:11.572 I/InputDispatcher( 220): Application is not responding:Window{2b263310com.android.email/com.android.email.activity.SplitScreenActivitypaused=false}.
5009.8ms since event, 5009.5ms since waitstarted
04-0113:12:11.572 I/WindowManager( 220): Input event
dispatching timedout sending
tocom.android.email/com.android.email.activity.SplitScreenActivity
04-01 13:12:14.123 I/Process( 220): Sending signal. PID: 21404 SIG:3---發生ANR的時間和生成trace.txt的時間
04-01 13:12:14.123 I/dalvikvm(21404):threadid=4: reacting to signal 3 ……
04-0113:12:15.872 E/ActivityManager( 220): ANR in com.android.email(com.android.email/.activity.SplitScreenActivity)
04-0113:12:15.872 E/ActivityManager( 220): Reason:keyDispatchingTimedOut -----ANR的型別
04-0113:12:15.872 E/ActivityManager( 220): Load: 8.68 / 8.37 / 8.53 --CPU的負載情況
04-0113:12:15.872 E/ActivityManager( 220): CPUusage from 4361ms to 699ms ago ----CPU在ANR發生前的使用情況;備註:這個ago,是發生前一段時間的使用情況,不是當前時間點的使用情況;
04-0113:12:15.872 E/ActivityManager( 220): 5.5%21404/com.android.email: 1.3% user + 4.1% kernel / faults:
10 minor
04-0113:12:15.872 E/ActivityManager( 220): 4.3%220/system_server: 2.7% user + 1.5% kernel / faults: 11
minor 2 major
04-0113:12:15.872 E/ActivityManager( 220): 0.9%52/spi_qsd.0: 0% user + 0.9% kernel
04-0113:12:15.872 E/ActivityManager( 220): 0.5%65/irq/170-cyttsp-: 0% user + 0.5% kernel
04-0113:12:15.872 E/ActivityManager( 220): 0.5%296/com.android.systemui: 0.5% user + 0% kernel
04-0113:12:15.872 E/ActivityManager( 220): 100%TOTAL: 4.8% user + 7.6% kernel + 87% iowait----注意這行:注意87%的iowait
04-0113:12:15.872 E/ActivityManager( 220): CPUusage from 3697ms to 4223ms later:-- ANR後CPU的使用量
04-0113:12:15.872 E/ActivityManager( 220): 25%21404/com.android.email: 25% user + 0% kernel / faults: 191 minor
04-0113:12:15.872 E/ActivityManager( 220): 16% 21603/__eas(par.hakan: 16% user + 0% kernel
04-0113:12:15.872 E/ActivityManager( 220): 7.2% 21406/GC: 7.2% user + 0% kernel
04-0113:12:15.872 E/ActivityManager( 220): 1.8% 21409/Compiler: 1.8% user + 0% kernel
04-0113:12:15.872 E/ActivityManager( 220): 5.5%220/system_server: 0% user + 5.5% kernel / faults: 1 minor
04-0113:12:15.872 E/ActivityManager( 220): 5.5% 263/InputDispatcher: 0% user + 5.5% kernel
04-0113:12:15.872 E/ActivityManager( 220): 32%TOTAL: 28% user + 3.7% kernel複製程式碼
從Logcat中可以得到以下資訊:
- 導致ANR的包名(com.android.emai),類名(com.android.email.activity.SplitScreenActivity),程式PID(21404)
- 導致ANR的原因:keyDispatchingTimedOut
- 系統中活躍程式的CPU佔用率,關鍵的一句:100%TOTAL: 4.8% user + 7.6% kernel + 87% iowait;表示CPU佔用滿負荷了,其中絕大數是被iowait即I/O操作佔用了。我們就可以大致得出是io操作導致的ANR。
限於篇幅有限,不在分析別的ANR型別。同時需要注意:並不是所有的ANR型別都有章可循,很多偶發的ANR受限於當時發生的環境或者系統Bug;因此對ANR,更應該強調預防而不是分析。
3、 ANR觸發場景
InputDispatching Timeout :輸入事件分發超時5s未響應完畢;
BroadcastQueue Timeout :前臺廣播在10s內、後臺廣播在20秒內未執行完成;
Service Timeout :前臺服務在20s內、後臺服務在200秒內未執行完成;
ContentProvider Timeout :內容提供者,在publish過超時10s;
4、 ANR觸發場景原始碼分析
系統的ANR機制是如何執行的,ANR是如何被出發的呢?
我們先來說說Service,主要用於在後臺處理一些耗時的邏輯,或者去執行某些需要長期執行的任務。但很多同志認為Service就可以執行耗時任務,這是一種誤解,Service本身也執行於主執行緒,執行耗時任務同樣會發生ANR。此處只分析Service Timeout的出發場景。
4.1 ANR的起源
Service的啟動過程由ContextWrapper開始,我們直接步入重點環節ActiveServices.java中realStartServiceLocked方法
// 此處僅列出精簡之後的程式碼;
private final void realStartServiceLocked(ServiceRecord r,ProcessRecord app, boolean execInFg) throws RemoteException {
/**
* 關鍵程式碼:傳送延時訊息,SERVICE_TIMEOUT_MSG,此處是Service ANR的源頭
*/
bumpServiceExecutingLocked(r, execInFg, "create");
try {
/**
* 接下來真正的建立Service物件,並執行Service的onCreate()方法
*/
app.thread.scheduleCreateService(r, r.serviceInfo,
mAm.compatibilityInfoForPackageLocked(r.serviceInfo.applicationInfo),
app.repProcState);
} catch (DeadObjectException e) {
Slog.w(TAG, "Application dead when creating service " + r);
mAm.appDiedLocked(app);
throw e;
}
}複製程式碼
其中bumpServiceExecutingLocked()方法又會呼叫到scheduleServiceTimeoutLocked()方法延時傳送SERVICE_TIMEOUT_MSG訊息。
/**
* 延時傳送SERVICE_TIMEOUT_MSG訊息,前、後臺Service時間不一樣。
* @param proc
*/
void scheduleServiceTimeoutLocked(ProcessRecord proc) {
if (proc.executingServices.size() == 0 || proc.thread == null) {
return;
}
long now = SystemClock.uptimeMillis();
Message msg = mAm.mHandler.obtainMessage(
ActivityManagerService.SERVICE_TIMEOUT_MSG);
msg.obj = proc;
mAm.mHandler.sendMessageAtTime(msg,
proc.execServicesFg ? (now+SERVICE_TIMEOUT) : (now+ SERVICE_BACKGROUND_TIMEOUT));
}複製程式碼
接下來呼叫到了ActivityThread.java的scheduleCreateService()方法,實際上使用Handler傳送了一條msg,最終呼叫到ActivityThread.java的handleCreateService()方法
private void handleCreateService(CreateServiceData data) {
try {
java.lang.ClassLoader cl = packageInfo.getClassLoader();
// 建立Service物件
service = (Service) cl.loadClass(data.info.name).newInstance();
} catch (Exception e) {
}
try {
// 呼叫Service的onCreate方法
service.onCreate();
mServices.put(data.token, service);
// 移除SERVICE_TIMEOUT_MSG的訊息
ActivityManagerNative.getDefault().serviceDoneExecuting(
data.token, SERVICE_DONE_EXECUTING_ANON, 0, 0);
} catch (Exception e) {
}
}複製程式碼
4.2 規定時間之內完成了方法的呼叫
ActivityManagerNative.getDefault().serviceDoneExecuting會執行到ActivityManagerService.java中的serviceDoneExecuting()方法,進而執行到ActiveService.java中的serviceDoneExecutingLocked()方法。此處意義:remove掉剛剛延時傳送的Message。
private void serviceDoneExecutingLocked(ServiceRecord r, boolean inDestroying,boolean finishing) {
if (r.app.executingServices.size() == 0) {
if (DEBUG_SERVICE || DEBUG_SERVICE_EXECUTING) Slog.v(TAG_SERVICE_EXECUTING,
"No more executingServices of " + r.shortName);
// 關鍵程式碼:remove掉剛剛延時傳送的Message,否則Message被執行,ANR就發生了;
mAm.mHandler.removeMessages(ActivityManagerService.SERVICE_TIMEOUT_MSG, r.app);
} else if (r.executeFg) {
// Need to re-evaluate whether the app still needs to be in the foreground.
for (int i=r.app.executingServices.size()-1; i>=0; i--) {
if (r.app.executingServices.valueAt(i).executeFg) {
r.app.execServicesFg = true;
break;
}
}
}
}複製程式碼
4.3 規定時間之內未完成方法的呼叫,出現了ANR
而如果Message沒有被mAm.mHandler(也就是ActivityManagerService中的MainHandler)及時remove掉,被執行的話就會出發ANR的發生;執行到ActivityManagerService中MainHandler的SERVICE_TIMEOUT_MSG然後呼叫到ActiveServices的serviceTimeout()方法,最終執行到ActivityManagerService的appNotResponding()方法。
//非常重要的方法,程式碼多留了點。
final void appNotResponding(ProcessRecord app, ActivityRecord activity,
ActivityRecord parent, boolean aboveSystem, final String annotation) {
ArrayList<Integer> firstPids = new ArrayList<Integer>(5);
SparseArray<Boolean> lastPids = new SparseArray<Boolean>(20);
synchronized (this) {
// Dump thread traces as quickly as we can, starting with "interesting" processes.
firstPids.add(app.pid);
int parentPid = app.pid;
if (parent != null && parent.app != null && parent.app.pid > 0) parentPid = parent.app.pid;
if (parentPid != app.pid) firstPids.add(parentPid);
if (MY_PID != app.pid && MY_PID != parentPid) firstPids.add(MY_PID);
for (int i = mLruProcesses.size() - 1; i >= 0; i--) {
ProcessRecord r = mLruProcesses.get(i);
if (r != null && r.thread != null) {
int pid = r.pid;
if (pid > 0 && pid != app.pid && pid != parentPid && pid != MY_PID) {
if (r.persistent) {
firstPids.add(pid);
} else {
lastPids.put(pid, Boolean.TRUE);
}
}
}
}
}
// 獲取ANR日誌資訊
StringBuilder info = new StringBuilder();
info.setLength(0);
info.append("ANR in ").append(app.processName);
if (activity != null && activity.shortComponentName != null) {
info.append(" (").append(activity.shortComponentName).append(")");
}
info.append("\n");
info.append("PID: ").append(app.pid).append("\n");
if (annotation != null) {
info.append("Reason: ").append(annotation).append("\n");
}
if (parent != null && parent != activity) {
info.append("Parent: ").append(parent.shortComponentName).append("\n");
}
final ProcessCpuTracker processCpuTracker = new ProcessCpuTracker(true);
File tracesFile = dumpStackTraces(true, firstPids, processCpuTracker, lastPids,
NATIVE_STACKS_OF_INTEREST);
String cpuInfo = null;
if (MONITOR_CPU_USAGE) {
updateCpuStatsNow();
synchronized (mProcessCpuTracker) {
cpuInfo = mProcessCpuTracker.printCurrentState(anrTime);
}
info.append(processCpuTracker.printCurrentLoad());
info.append(cpuInfo);
}
info.append(processCpuTracker.printCurrentState(anrTime));
Slog.e(TAG, info.toString());
if (tracesFile == null) {
// There is no trace file, so dump (only) the alleged culprit's threads to the log
Process.sendSignal(app.pid, Process.SIGNAL_QUIT);
}
// 新增到DropBox,2.3之後出的功能,解決traces.txt被覆蓋的問題
addErrorToDropBox("anr", app, app.processName, activity, parent, annotation,
cpuInfo, tracesFile, null);
// 獲取設定,確認是否需要彈出ANR提示框,需要的話彈出,不需要的話直接kill。
boolean showBackground = Settings.Secure.getInt(mContext.getContentResolver(),
Settings.Secure.ANR_SHOW_BACKGROUND, 0) != 0;
synchronized (this) {
mBatteryStatsService.noteProcessAnr(app.processName, app.uid);
if (!showBackground && !app.isInterestingToUserLocked() && app.pid != MY_PID) {
// kill 程式
app.kill("bg anr", true);
return;
}
// Set the app's notResponding state, and look up the errorReportReceiver
makeAppNotRespondingLocked(app,
activity != null ? activity.shortComponentName : null,
annotation != null ? "ANR " + annotation : "ANR",
info.toString());
// Bring up the infamous App Not Responding dialog
Message msg = Message.obtain();
HashMap<String, Object> map = new HashMap<String, Object>();
msg.what = SHOW_NOT_RESPONDING_MSG;
msg.obj = map;
msg.arg1 = aboveSystem ? 1 : 0;
map.put("app", app);
if (activity != null) {
map.put("activity", activity);
}
// 去彈出ANR提示框。
mUiHandler.sendMessage(msg);
}
}複製程式碼
流程總結:
1. Service建立之前會延遲傳送一個訊息,而這個訊息就是ANR的起源;
2. Service建立完畢,在規定的時間之內執行完畢onCreate()方法就移除這個訊息,就不會產生ANR了;
3. 在規定的時間之內沒有完成onCreate()的呼叫,訊息被執行,ANR發生。
5、 其它
1、Service建立過程中對onCreate()埋下了ANR的起源,其中不能執行超過規定時間的操作,那是不是可以移到onStartCommand()方法中?
真是機智的同學,點個贊!然而事實並不是這樣的,onStartCommond()方法的呼叫是在ActiveServices.java的sendServiceArgsLocked(),這個過程和onCreate()很類似,都會延時傳送Message,然後在規定時間內執行完畢的話移除;沒有完成的話發生ANR!
2、回到上面的問題:在《Multidex(二)之 Dex 預載入優化》中採用單獨開程式執行Dex預載入優化的操作時,主程式在後臺sleep(),為什麼不會出現ANR呢?
答案是不是很清晰了:回憶下ANR的觸發場景,此時主程式處於後臺,無法響應按鍵、觸控等事件,同時此時也並沒有Service等發生ANR的條件,因此主程式只是在後臺等待,不會發生ANR。這種思路在MultiDex以及外掛化方案中都有實踐。
歡迎關注微信公眾號:定期分享Java、Android乾貨!