android系統穩定性-ANR(二)
P.S. OpenOffice貼上過來後格式有些混亂。
1.2如何分析ANR問題
引起ANR問題的根本原因,總的來說可以歸納為兩類:
-
應用程序自身引起的,例如:
主執行緒阻塞、掛起、死迴圈
應用程序的其他執行緒的CPU佔用率高,使得主執行緒無法搶佔到CPU時間片
-
其他程序間接引起的,例如:
當前應用程序進行程序間通訊請求其他程序,其他程序的操作長時間沒有反饋
其他程序的CPU佔用率高,使得當前應用程序無法搶佔到CPU時間片
分析ANR問題時,以上述可能的幾種原因為線索,通過分析各種日誌資訊,大多數情況下你就可以很容易找到問題所在了。
注意:我很誠懇的向讀者說明,確實有一些
1.2.1 分析ANR的利器
Android會在ANR發生時輸出很多有用的資訊幫助分析問題原因,我們先來看一下
//WindowManager所在的程序是system_server,程序號是127
I/WindowManager( 127): Input event dispatching timed out sending to com.example.anrdemo/com.example.anrdemo.ANRActivity
//system_server程序中的ActivityManagerService請求kernel向5033程序傳送SIGNAL_QUIT請求
//你可以在shell中使用命令達到相同的目的:adb
shell kill -3 5033
//和其他的Java虛擬機器一樣,SIGNAL_QUIT也是Dalvik內部支援的功能之一
I/Process ( 127): Sending signal. PID: 5033 SIG: 3
//5033程序的虛擬機器例項接收到SIGNAL_QUIT訊號後會將程序中各個執行緒的函式堆疊資訊輸出到traces.txt檔案中
//發生ANR的程序正常情況下會第一個輸出
I/dalvikvm( 5033): threadid=4: reacting to signal 3
I/dalvikvm( 5033): Wrote stack traces to '/data/anr/traces.txt'
... ...//另外還有其他一些程序
//隨後會輸出CPU使用情況
E/ActivityManager( 127): ANR in com.example.anrdemo (com.example.anrdemo/.ANRActivity)
//Reason表示導致ANR問題的直接原因
E/ActivityManager( 127): Reason: keyDispatchingTimedOut
E/ActivityManager( 127): Load: 3.85 / 3.41 / 3.16
//請注意ago,表示ANR發生之前的一段時間內的CPU使用率,並不是某一時刻的值
E/ActivityManager( 127): CPU usage from 26835ms to 3662ms ago with 99% awake:
E/ActivityManager( 127): 9.4% 98/mediaserver: 9.4% user + 0% kernel
E/ActivityManager( 127): 8.9% 127/system_server: 6.9% user + 2% kernel / faults: 1823 minor
... ...
E/ActivityManager( 127): +0% 5033/com.example.anrdemo: 0% user + 0% kernel
E/ActivityManager( 127): 39% TOTAL: 32% user + 6.1% kernel
//這裡是later,表示ANR發生之後
E/ActivityManager( 127): CPU usage from 601ms to 1132ms later with 99% awake:
E/ActivityManager( 127): 10% 127/system_server: 1.7% user + 8.9% kernel / faults: 5 minor
E/ActivityManager( 127): 10% 163/InputDispatcher: 1.7% user + 8.9% kernel
E/ActivityManager( 127): 1.7% 127/system_server: 1.7% user + 0% kernel
E/ActivityManager( 127): 1.7% 135/SurfaceFlinger: 0% user + 1.7% kernel
E/ActivityManager( 127): 1.7% 2814/Binder Thread #: 1.7% user + 0% kernel
... ...
E/ActivityManager( 127): 37% TOTAL: 27% user + 9.2% kernel
從log中能夠知道,發生ANR時Android為我們提供了兩種“利器”:traces檔案和CPU使用率。以上做了簡單註釋,不過稍後再詳細分析它們。
1.2.2 ANR資訊是如何輸出的
我們再來看看這些log是怎樣被輸出的,這很重要,知其然,也要知其所以然。程式碼在ActivityManagerService類中,找到它的appNotResponding函式。
final void appNotResponding(ProcessRecord app, ActivityRecord activity,
ActivityRecord parent, final String annotation) {
//firstPids和lastPids兩個集合存放那些將會在traces中輸出資訊的程序的程序號
ArrayList<Integer> firstPids = new ArrayList<Integer>(5);
SparseArray<Boolean> lastPids = new SparseArray<Boolean>(20);
//mController是IActivityController介面的例項,是為Monkey測試程式預留的,預設為null
if (mController != null) {
... ...
}
long anrTime = SystemClock.uptimeMillis();
if (MONITOR_CPU_USAGE) {
updateCpuStatsNow(); //更新CPU使用率
}
synchronized (this) { //一些特定條件下會忽略ANR
if (mShuttingDown) {
Slog.i(TAG, "During shutdown skipping ANR: " + app + " " + annotation);
return;
} else if (app.notResponding) {
Slog.i(TAG, "Skipping duplicate ANR: " + app + " " + annotation);
return;
} else if (app.crashing) {
Slog.i(TAG, "Crashing app skipping ANR: " + app + " " + annotation);
return;
}
//使用一個標誌變數避免同一個應用在沒有處理完時重複輸出log
app.notResponding = true;
... ...
//①當前發生ANR的應用程序被第一個新增進firstPids集合中
firstPids.add(app.pid);
... ...
}
... ...
//②dumpStackTraces是輸出traces檔案的函式
File tracesFile = dumpStackTraces(true, firstPids, processStats, lastPids, null);
String cpuInfo = null;
if (MONITOR_CPU_USAGE) { //MONITOR_CPU_USAGE預設為true
updateCpuStatsNow(); //再次更新CPU資訊
synchronized (mProcessStatsThread) {
//輸出ANR發生前一段時間內的CPU使用率
cpuInfo = mProcessStats.printCurrentState(anrTime);
}
info.append(processStats.printCurrentLoad());
info.append(cpuInfo);
}
//輸出ANR發生後一段時間內的CPU使用率
info.append(processStats.printCurrentState(anrTime));
... ...
//③將ANR資訊同時輸出到DropBox中
addErrorToDropBox("anr", app, app.processName, activity, parent, annotation,
cpuInfo, tracesFile, null);
... ...
//在Android4.0中可以設定是否不顯示ANR提示對話方塊,如果設定的話就不會顯示對話方塊,並且會殺掉ANR程序
boolean showBackground = Settings.Secure.getInt(mContext.getContentResolver(),
Settings.Secure.ANR_SHOW_BACKGROUND, 0) != 0;
synchronized (this) {
if (!showBackground && !app.isInterestingToUserLocked() && app.pid != MY_PID) {
... ...
Process.killProcessQuiet(app.pid);
return;
}
... ...
//顯示ANR提示對話方塊
Message msg = Message.obtain();
HashMap map = new HashMap();
msg.what = SHOW_NOT_RESPONDING_MSG;
msg.obj = map;
map.put("app", app);
if (activity != null) {
map.put("activity", activity);
}
mHandler.sendMessage(msg);
}
}
有三個關鍵點需要注意:
①當前發生ANR的應用程序被第一個新增進firstPids集合中,所以會第一個向traces檔案中寫入資訊。反過來說,traces檔案中出現的第一個程序正常情況下就是發生ANR的那個程序。不過有時候會很不湊巧,發生ANR的程序還沒有來得及輸出trace資訊,就由於某種原因退出了,所以偶爾會遇到traces檔案中找不到發生ANR的程序資訊的情況。
② dumpStackTraces是輸出traces檔案的函式,接下來分析這個函式
③ addErrorToDropBox函式將ANR資訊同時輸出到DropBox中,它也是個非常有用的日誌存放工具,後面也會分析它的作用。
public static File dumpStackTraces(boolean clearTraces, ArrayList<Integer> firstPids,
ProcessStats processStats, SparseArray<Boolean> lastPids, String[] nativeProcs) {
//系統屬性“dalvik.vm.stack-trace-file”用來配置trace資訊輸出檔案
String tracesPath = SystemProperties.get("dalvik.vm.stack-trace-file", null);
if (tracesPath == null || tracesPath.length() == 0) {
return null;
}
File tracesFile = new File(tracesPath);
try {
File tracesDir = tracesFile.getParentFile();
if (!tracesDir.exists()) tracesFile.mkdirs();
//FileUtils.setPermissions是個很有用的函式,設定檔案屬性時經常會用到
FileUtils.setPermissions(tracesDir.getPath(), 0775, -1, -1); // drwxrwxr-x
//clearTraces為true,會刪除舊檔案,建立新檔案
if (clearTraces && tracesFile.exists()) tracesFile.delete();
tracesFile.createNewFile();
FileUtils.setPermissions(tracesFile.getPath(), 0666, -1, -1); // -rw-rw-rw-
} catch (IOException e) {
Slog.w(TAG, "Unable to prepare ANR traces file: " + tracesPath, e);
return null;
}
//一個過載函式
dumpStackTraces(tracesPath, firstPids, processStats, lastPids, nativeProcs);
return tracesFile;
}
有兩個關鍵點需要注意:
①聰明的你肯定已經知道,之所以trace資訊會輸出到“/data/anr/traces.txt”檔案中,就是系統屬性“dalvik.vm.stack-trace-file”設定的。你可以通過在裝置的shell中使用setprop和getprop對系統屬性進行設定和讀取:
getpropdalvik.vm.stack-trace-file
setprop dalvik.vm.stack-trace-file /tmp/stack-traces.txt
②每次發生ANR時都會刪除舊的traces檔案,重新建立新檔案。也就是說Android只保留最後一次發生ANR時的traces資訊,那麼以前的traces資訊就丟失了麼?稍後回答。
接著來看過載的dumpStackTraces函式。
private static void dumpStackTraces(String tracesPath, ArrayList<Integer> firstPids,
ProcessStats processStats, SparseArray<Boolean> lastPids, String[] nativeProcs) {
//使用FileObserver監聽應用程序是否已經完成寫入traces檔案的操作
//Android在判斷桌面桌布檔案是否設定完成時也是用的FileObserver,很有用的類
FileObserver observer = new FileObserver(tracesPath, FileObserver.CLOSE_WRITE) {
public synchronized void onEvent(int event, String path) { notify(); }
};
... ...
//首先輸出firstPids集合中指定的程序,這些也是對ANR問題來說最重要的程序
if (firstPids != null) {
try {
int num = firstPids.size();
for (int i = 0; i < num; i++) {
synchronized (observer) {
//前面提到的SIGNAL_QUIT
Process.sendSignal(firstPids.get(i), Process.SIGNAL_QUIT);
observer.wait(200);
... ...
}
提示:如果你在解決其他問題時也需要檢視Java程序中各個執行緒的函式堆疊資訊,就可以使用向目標程序傳送SIGNAL_QUIT(3)這個技巧。其實這個名稱有點誤導,它並不會讓程序真正退出。
1.2.3 DropBox
剛才留了一個問題:Android只保留最後一次發生ANR時的traces資訊,那麼以前的traces資訊就丟失了麼?為了增強Android的異常資訊收集管理能力,從2.2開始增加了DropBox功能。
DropBox(簡稱DB)是系統程序中的一個服務,在system_server程序啟動時建立,並且它沒有執行在單獨的執行緒中,而是執行在system_server的ServerThread執行緒中。我們可以將ServerThread稱作system_server的主執行緒,ServerThread執行緒除了啟動並維護各個服務外,還負責檢測一些重要的服務是否死鎖,這一點到後面的Watchdog部分再分析