Android 系統穩定性 - ANR（二）

時間 2019-12-02

標籤 android 系統穩定性 anr 欄目 Android 简体版

原文原文鏈接

【原創】Android 系統穩定性 - ANR（二）

文章都爲原創，轉載請註明出處，未經容許而盜用者追究法律責任。
好久以前寫的了，留着有點浪費，共享之。
編寫者：李文棟
P.S. OpenOffice粘貼過來後格式有些混亂。java

1.2 如何分析ANR問題

引發ANR問題的根本緣由，總的來講能夠概括爲兩類：react

應用進程自身引發的，例如：android

主線程阻塞、掛起、死循環算法

應用進程的其餘線程的CPU佔用率高，使得主線程沒法搶佔到CPU時間片shell

其餘進程間接引發的，例如：數據庫

當前應用進程進行進程間通訊請求其餘進程，其餘進程的操做長時間沒有反饋緩存

其餘進程的CPU佔用率高，使得當前應用進程沒法搶佔到CPU時間片服務器

分析ANR問題時，以上述可能的幾種緣由爲線索，經過分析各類日誌信息，大多數狀況下你就能夠很容易找到問題所在了。app

注意：我很誠懇的向讀者說明，確實有一些ANR問題很難調查清楚，由於整個系統不穩定的因素不少，例如Linux Kernel自己的bug引發的內存碎片過多、硬件損壞等。這類比較底層的緣由引發的ANR問題每每無從查起，而且這根本不是應用程序的問題，浪費了應用開發人員不少時間，若是你從事過整個系統的開發和維護工做的話會深有體會。因此我不能保證瞭解了本章的全部內容後可以解決一切ANR問題，若是出現了很疑難的ANR問題，我建議最好去和作驅動和內核的朋友聊聊，或者，若是問題只是個十萬分之一的偶然現象，不影響程序的正常運行，我卻是建議不去理它。ide

1.2.1 分析ANR的利器

Android會在ANR發生時輸出不少有用的信息幫助分析問題緣由，咱們先來看一下ANR的異常信息，使用logcat命令查看會獲得相似以下的log：

//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部分再分析。DB被建立的代碼以下。

SystemServer.java → ServerThread.run()

Slog.i(TAG, "DropBox Service");

ServiceManager.addService(Context.DROPBOX_SERVICE, //服務名稱爲「dropbox」

new DropBoxManagerService(context, new File("/data/system/dropbox")));

「/data/system/dropbox」是DB指定的文件存放位置。下面來看一下DB服務的主要功能。

1. DropBoxManagerService

DropBoxManagerService（簡稱DBMS）就是DB服務的本尊，它的主要功能接口包括如下幾個函數：

public voidadd(DropBoxManager.Entryentry)

DBMS將全部要添加的日誌都用DropBoxManager.Entry類型的對象表示，經過add函數添加，而且直到目前爲止一個Entry對象對應着一個日誌文件。

publicboolean isTagEnabled(String tag)

經過給每個Entry設置一個tag能夠標識不一樣類型的日誌，而且能夠靈活的啓用/禁用某種類型的日誌，isTagEnabled用來判斷指定類型的日誌是否被啓用/禁用了，一旦禁用就不會再記錄這種類型的日誌。默認是不由用任何類型的日誌的。稍後說明如何啓用/禁用日誌。

publicsynchronized DropBoxManager.Entry getNextEntry(String tag, long millis)

咱們能夠經過getNextEntry函數獲取指定類型和指定時間點以後的第一條日誌，要使用這個功能應用程序須要有「android.permission.READ_LOGS」的權限，而且在使用完畢返回的Entry對象後要調用其close函數確保關閉日誌文件的文件描述符（若是不關閉的話可能形成進程打開的文件描述符超過1024而崩潰，Android中限制每一個進程的文件描述符上限爲1024）。

DBMS提供了不少的配置項用來限制對磁盤的使用，經過SettingsProvider應用程序維護，數據存放在其settings.db數據庫中。這些配置項也都有默認值，羅列以下：

Settings.Secure.DROPBOX_AGE_SECONDS = "dropbox_age_seconds"

日誌文件保存的最長時間，默認3天

Settings.Secure.DROPBOX_MAX_FILES = "dropbox_max_files"

日誌文件的最大數量，默認值是1000

Settings.Secure.DROPBOX_QUOTA_KB = "dropbox_quota_kb"

磁盤空間最大使用量

Settings.Secure.DROPBOX_QUOTA_PERCENT = "dropbox_quota_percent"

Settings.Secure.DROPBOX_RESERVE_PERCENT = "dropbox_reserve_percent"

Settings.Secure.DROPBOX_TAG_PREFIX = "dropbox:"

//應用程序能夠利用DropBox來作事情，收集日誌等

1.2.4 traces.txt

終於到大明星出場的時候了，一塊兒來看一下traces.txt的廬山真面目。如下是筆者寫的一個演示程序製造出的一次ANR的trace信息：

//文件中輸出的第一個進程的trace信息，正是發生ANR的演示程序

//開頭顯示進程號、ANR發生的時間點和進程名稱

----- pid 9183 at 2012-09-28 22:20:42 -----

Cmd line: com.example.anrdemo

DALVIK THREADS: //如下是各個線程的函數堆棧信息

//mutexes表示虛擬機實例中各類線程相關對象鎖的value值

(mutexes: tll=0 tsl=0 tscl=0 ghl=0 hwl=0 hwll=0)

//依次是：線程名、線程優先級、線程建立時的序號、①線程當前狀態

"main" prio=5 tid=1 TIMED_WAIT

//依次是：線程組名稱、suspendCount、debugSuspendCount、線程的Java對象地址、線程的Native對象地址

| group="main" sCount=1 dsCount=0 obj=0x4025b1b8 self=0xce68

//sysTid是線程號，主線程的線程號和進程號相同

| sysTid=9183 nice=0 sched=0/0 cgrp=default handle=-1345002368

| schedstat=( 140838632 210998525 213 )

at java.lang.VMThread.sleep(Native Method)

at java.lang.Thread.sleep(Thread.java:1213)

at java.lang.Thread.sleep(Thread.java:1195)

at com.example.anrdemo.ANRActivity.makeANR(ANRActivity.java:44)

at com.example.anrdemo.ANRActivity.onClick(ANRActivity.java:38)

at android.view.View.performClick(View.java:2486)

at android.view.View$PerformClick.run(View.java:9130)

at android.os.Handler.handleCallback(Handler.java:587)

at android.os.Handler.dispatchMessage(Handler.java:92)

at android.os.Looper.loop(Looper.java:130)

at android.app.ActivityThread.main(ActivityThread.java:3703)

at java.lang.reflect.Method.invokeNative(Native Method)

at java.lang.reflect.Method.invoke(Method.java:507)

at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:841)

at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:599)

at dalvik.system.NativeStart.main(Native Method)

//②Binder線程是進程的線程池中用來處理binder請求的線程

"Binder Thread #2" prio=5 tid=8 NATIVE

| group="main" sCount=1 dsCount=0 obj=0x40750b90 self=0x1440b8

| sysTid=9190 nice=0 sched=0/0 cgrp=default handle=1476256

| schedstat=( 915528 18463135 4 )

at dalvik.system.NativeStart.run(Native Method)

"Binder Thread #1" prio=5 tid=7 NATIVE

| group="main" sCount=1 dsCount=0 obj=0x4074f848 self=0x78d40

| sysTid=9189 nice=0 sched=0/0 cgrp=default handle=1308088

| schedstat=( 3509523 25543212 10 )

at dalvik.system.NativeStart.run(Native Method)

//線程名稱後面標識有daemon，說明這是個守護線程

"Compiler" daemon prio=5 tid=6 VMWAIT

| group="system" sCount=1 dsCount=0 obj=0x4074b928 self=0x141e78

| sysTid=9188 nice=0 sched=0/0 cgrp=default handle=1506000

| schedstat=( 21606438 21636964 101 )

at dalvik.system.NativeStart.run(Native Method)

//JDWP線程是支持虛擬機調試的線程，不須要關心

"JDWP" daemon prio=5 tid=5 VMWAIT

| group="system" sCount=1 dsCount=0 obj=0x4074b878 self=0x16c958

| sysTid=9187 nice=0 sched=0/0 cgrp=default handle=1510224

| schedstat=( 366211 2807617 7 )

at dalvik.system.NativeStart.run(Native Method)

//「Signal Catcher」負責接收和處理kernel發送的各類信號，例如SIGNAL_QUIT、SIGNAL_USR1等就是被該線程

//接收到，這個文件的內容就是由該線程負責輸出的，能夠看到它的狀態是RUNNABLE，不過此線程也不須要關心

"Signal Catcher" daemon prio=5 tid=4 RUNNABLE

| group="system" sCount=0 dsCount=0 obj=0x4074b7b8 self=0x150008

| sysTid=9186 nice=0 sched=0/0 cgrp=default handle=1501664

| schedstat=( 1708985 6286621 9 )

at dalvik.system.NativeStart.run(Native Method)

"GC" daemon prio=5 tid=3 VMWAIT

| group="system" sCount=1 dsCount=0 obj=0x4074b710 self=0x168010

| sysTid=9185 nice=0 sched=0/0 cgrp=default handle=1503184

| schedstat=( 305176 4821778 2 )

at dalvik.system.NativeStart.run(Native Method)

"HeapWorker" daemon prio=5 tid=2 VMWAIT

| group="system" sCount=1 dsCount=0 obj=0x4074b658 self=0x16a080

| sysTid=9184 nice=0 sched=0/0 cgrp=default handle=550856

| schedstat=( 33691407 26336669 15 )

at dalvik.system.NativeStart.run(Native Method)

----- end 9183 -----

----- pid 127 at 2012-09-28 22:20:42 -----

Cmd line: system_server

... ...

//省略其餘進程的信息

有一個關鍵點須要注意：

➀ 線程有不少狀態，瞭解這些狀態的意義對分析ANR的緣由是有幫助的，總結以下：

Thread.java中的狀態和Thread.cpp中的狀態是有對應關係的。能夠看到前者更加歸納，也比較容易理解，面向Java的使用者；然後者更詳細，面向虛擬機內部的環境。traces.txt中顯示的線程狀態都是Thread.cpp中定義的。另外，全部的線程都是遵循POSIX標準的本地線程。關於線程更多的說明能夠查閱源碼/dalvik/vm/Thread.cpp中的說明。

traces.txt文件中的這些信息是由每一個Dalvik進程的SignalCatcher線程輸出的，相關代碼能夠查看/dalvik/vm/目錄下的SignalCatcher.cpp::logThreadStacks函數和Thread.cpp:: dvmDumpAllThreadsEx函數。另外請注意，輸出堆棧信息時SignalCatcher會暫停全部線程。

經過該文件很容易就能知道問題進程的主線程發生ANR時正在執行怎樣的操做。例如上述示例，ANRActivity在makeANR函數中執行線程sleep時發生ANR，能夠推測sleep時間過長，超過了超時上限致使。這是一種比較簡單的狀況，實際開發中會遇到不少詭異的、更加複雜的狀況，在後面的實例講解一節會詳細說明。

1.2.5 CPU使用率

這部分的內容主要涉及到Linux的相關知識，數據是從「/proc/stat」文件中讀取的，Android中僅僅是彙總和記錄這些數據而已，熟悉Linux的讀者能夠跳過本節內容。

前面簡單說明了CPU使用率信息，咱們回顧一下，此次會有更多的知識點要說明。

E/ActivityManager( 127): ANR in com.example.anrdemo (com.example.anrdemo/.ANRActivity)

E/ActivityManager( 127): Reason: keyDispatchingTimedOut

E/ActivityManager( 127): Load: 3.85 / 3.41 / 3.16 //➀ CPU平均負載

//②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 //⑤ minor或者major的頁錯誤次數

... ...

E/ActivityManager( 127)://⑥+0% 5033/com.example.anrdemo: 0% user + 0% kernel

E/ActivityManager( 127): 39% TOTAL: 32% user + 6.1% kernel

//⑦ANR發生以後的一段時間內的CPU使用率

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

以上信息其實包含了兩個概念：CPU負載和CPU使用率，它們是不一樣的。不過負載的概念主要是作大型服務器端應用時關注的性能指標，在Android開發中咱們更加關注的是使用率。下面詳細說明，有八個關鍵點須要注意：

① CPU負載/平均負載

CPU負載是指某一時刻系統中運行隊列長度之和加上當前正在CPU上運行的進程數，而CPU平均負載能夠理解爲一段時間內正在使用和等待使用CPU的活動進程的平均數量。在Linux中「活動進程」是指當前狀態爲運行或不可中斷阻塞的進程。一般所說的負載其實就是指平均負載。

用一個從網上看到的很生動的例子來講明（不考慮CPU時間片的限制），把設備中的一個單核CPU比做一個電話亭，把進程比做正在使用和等待使用電話的人，假若有一我的正在打電話，有三我的在排隊等待，此刻電話亭的負載就是4。使用中會不斷的有人打完電話離開，也會不斷的有其餘人排隊等待，爲了獲得一個有參考價值的負載值，能夠規定每隔5秒記錄一下電話亭的負載，並將某一時刻以前的一分鐘、五分鐘、十五分鐘的的負載狀況分別求平均值，最終就獲得了三個時段的平均負載。

實際上咱們一般關心的就是在某一時刻的前一分鐘、五分鐘、十五分鐘的CPU平均負載，例如以上日誌中這三個值分別是3.85、3.41、3.16，說明前一分鐘內正在使用和等待使用CPU的活動進程平均有3.85個，依此類推。在大型服務器端應用中主要關注的是第五分鐘和第十五分鐘的兩個值，可是Android主要應用在便攜手持設備中，有特殊的軟硬件環境和應用場景，短期內的系統的較高負載就有可能形成ANR，因此筆者認爲一分鐘內的平均負載相對來講更具備參考價值。

CPU的負載和使用率沒有必然關係，有可能只有一個進程在使用CPU，但執行的是複雜的操做；也有可能等待和正在使用CPU的進程不少，但每一個進程執行的都是簡單操做。

實際處理問題時偶爾會遇到因爲平均負載高引發的ANR，典型的特徵就是系統中應用進程數量多，CPU總使用率較高，可是每一個進程的CPU使用率不高，當前應用進程主線程沒有異常阻塞，一分鐘內的CPU平均負載較高。

提示：Linux內核不斷進行着CPU負載的記錄，咱們能夠在任意時刻經過在shell中執行「cat /proc/loadavg」查看。

② ANR發生以前和以後一段時間的CPU使用率

CPU使用率能夠理解爲一段時間（記做T）內除CPU空閒時間（記做I）以外的時間與這段時間T的比值，用公式表示能夠寫爲：

CPU使用率= (T – I) / T

而時間段T是兩個採樣時間點的時間差值。

之因此能夠這樣計算，是由於Linux內核會把從系統啓動開始到當前時刻CPU活動的全部時間信息都記錄下來，咱們能夠經過查看「/proc/stat」文件獲取這些信息。主要包括如下幾種時間，這些時間都是從系統啓動開始計算的，單位都是0.01秒：

user： CPU在用戶態的運行時間，不包括nice值爲負數的進程運行的時間

nice： CPU在用戶態而且nice值爲負數的進程運行的時間

system：CPU在內核態運行的時間

idle： CPU空閒時間，不包括iowait時間

iowait： CPU等待I/O操做的時間

irq： CPU硬中斷的時間

softirq：CPU軟中斷的時間

注意：隨着Linux內核版本的不一樣，包含的時間類型有可能不一樣，例如2.6.11中增長的stealstolen等。但根據Android源碼，咱們只須要關心以上七種類型便可。

CPU使用率的計算是在ProcessStats類中實現的。若是在某兩個時刻T1和T2（T1 < T2）進行採樣記錄，CPU使用率的整個算法能夠概括爲如下幾個公式：

userTime = (user2 + nice2) – (user1 + nice1)

systemTime = system2 - system1

idleTime = idle2 - idle1

iowaitTime = iowait2 - iowait1

irqTime = irq2 - irq1

softirqTime = softirq2 - softirq1

TotalTime = userTime + systemTime + idleTime + iowaitTime + irqTime + softirqTime

有了以上數據就能夠計算具體的使用率了，例如用戶態CPU使用率爲：

userCpuUsage = userTime / TotalTime

依此類推能夠計算其餘類型的使用率。而整個時間段內CPU使用率爲：

CpuUsage = (TotalTime – idleTime) / TotalTime

以上計算的是整個系統的CPU使用率，對於指定進程的使用率是經過讀取該進程的「/proc/進程號/stat」文件計算的，而對於指定進程的指定線程的使用率是經過讀取該線程的「/proc/進程號/task/線程號/stat」文件計算的。進程和線程的CPU使用率只包含該進程或線程的總使用率、用戶態使用率和內核態使用率。

AMS在執行appNotResponding函數過程當中，共輸出了兩個時間段的CPU使用率，一般狀況下在ANR發生時間點以前和以後各有一段。兩段使用率都是兩次調用ProcessStats對象的update函數，每次調用update函數時會保留上一時間點的採樣數據，並記錄當前時間點的採樣數據。而後再調用ProcessStats對象的printCurrentState函數，按照上述公式概括的算法計算CPU使用率，並輸出最終的結果。再詳細看一下代碼：

ActivityManagerService.java → appNotResponding

//第一次使用成員變量mProcessStats採樣

if (MONITOR_CPU_USAGE) {

updateCpuStatsNow();

}

... ...

//聲明瞭一個局部變量，參數true表示包括線程信息

final ProcessStats processStats = new ProcessStats(true);

//將processStats做爲實參傳入，在dumpStackTraces中相隔500毫秒兩次調用其update函數進行採樣

File tracesFile = dumpStackTraces(true, firstPids, processStats, lastPids);

String cpuInfo = null;

if (MONITOR_CPU_USAGE) {

//由於在第一次調用後，可能因爲輸出trace信息等操做，中間執行了較長的時間，因此有第二次使用成員變量

//mProcessStats採樣，儘可能使得采樣時間點靠後。

//此函數中要求連續兩次採樣時間間隔很多於5秒，因此通常不會執行第二次採樣。一旦執行，就會出現兩個採樣

//時間點一個在ANR發生以前，另外一個在其以後，或者兩個時間點都在ANR發生以後的狀況。

updateCpuStatsNow();

synchronized (mProcessStatsThread) {

//mProcessStats是成員變量，建立對象時傳入的參數是false，因此不包括線程信息

//此處先輸出ANR發生以前一段時間內的CPU使用率

cpuInfo = mProcessStats.printCurrentState(anrTime);

}

info.append(processStats.printCurrentLoad());

info.append(cpuInfo);

}

//processStats對象是在ANR發生後建立並採樣的，因此輸出的是ANR發生以後一段時間內的CPU使用率

info.append(processStats.printCurrentState(anrTime));

③ 非睡眠時間百分比

在記錄CPU使用率的每一個採樣時間點時使用了兩種記錄方法：SystemClock.uptimeMillis()和SystemClock.elapsedRealtime()，二者的區別就是uptimeMillis不包含睡眠時間，因此兩個採樣時間點之間的uptimeMillis和elapsedRealtime之比就是非睡眠時間百分比。

➃頁錯誤次數

進程的CPU使用率最後輸出的「faults: xxx minor/major」部分表示的是頁錯誤次數，當次數爲0時不顯示。major是指Major Page Fault（主要頁錯誤，簡稱MPF），內核在讀取數據時會前後查找CPU的高速緩存和物理內存，若是找不到會發出一個MPF信息，請求將數據加載到內存。Minor是指Minor Page Fault（次要頁錯誤，簡稱MnPF），磁盤數據被加載到內存後，內核再次讀取時，會發出一個MnPF信息。一個文件第一次被讀寫時會有不少的MPF，被緩存到內存後再次訪問MPF就會不多，MnPF反而變多，這是內核爲減小效率低下的磁盤I/O操做採用的緩存技術的結果。