一、認識ANR
1、 ANR的定義
ANR,是“Application Not Responding”的縮寫,即“應用程序無響應”。如果你應用程序在UI線程被阻塞太長時間,就會出現ANR,通常出現ANR,系統會彈出一個提示提示框,讓用戶知道,該程序正在被阻塞,是否繼續等待還是關閉。
2、ANR的類型
(1)KeyDispatchTimeout(常見)
input事件在5S內沒有處理完成發生了ANR。
logcat日志關鍵字:Input event dispatching timed out
(2)BroadcastTimeout
前臺Broadcast:onReceiver在10S內沒有處理完成發生ANR。
后臺Broadcast:onReceiver在60s內沒有處理完成發生ANR。
logcat日志關鍵字:Timeout of broadcast BroadcastRecord
(3)ServiceTimeout
前臺Service:onCreate,onStart,onBind等生命周期在20s內沒有處理完成發生ANR。
后臺Service:onCreate,onStart,onBind等生命周期在200s內沒有處理完成發生ANR
logcat日志關鍵字:Timeout executing service
(4)ContentProviderTimeout
ContentProvider 在10S內沒有處理完成發生ANR。
logcat日志關鍵字:timeout publishing content providers
3、ANR出現的原因
(1)主線程頻繁進行耗時的IO操作:如數據庫讀寫
(2)多線程操作的死鎖,主線程被block;
(3)主線程被Binder 對端block;
(4)System Server中WatchDog出現ANR;
(5)service binder的連接達到上線無法和和System Server通信
(6)系統資源已耗盡(管道、CPU、IO)
4、如何分析ANR
(1)日志分析:ANR發生時都會在log中輸出錯誤信息,從log中可以獲得ANR的類型,CPU的使用情況,CPU使用率過高有可能是CPU饑餓導致了ANR。CPU使用率過低說明主線程被block了,如果IOwait高是因為主線程進行I/O操作造成的。
(2)traces文件分析:除了log輸出外,你會發現各個應用進程和系統進程的函數堆棧信息都輸出到了一個/data/anr/traces.txt的文件中,這個文件是分析ANR原因的關鍵文件.要獲取到該文件可使用adb指令進行賦權后拉出查看調用stack。通過log、trace.text、代碼結合分析ANR的成因(iowait?Memoryleak?Block?)
(3)traces文件無法分析的:不過還存在一些ANR問題,trace文件是分析不了的,例如我們的系統上,人臉識別活體攻擊的時候,native算法耗盡cpu資源導致其他app無法搶占cpu時間片導致anr,假如ANR的app是你開發的,估計查到死也找不到問題所在,類似這類問題也寫過簡要的分析文章:
接下來我們將一步一步分析ANR,這個過程能讓我們進一步明白如何找到問題、分析問題以及解決問題。
二、ANR發生時調用的關鍵代碼
當ANR發生的時候,系統會調用如下相關的關鍵函數代碼,來將系統當前的關鍵信息保存到日志當中:
Javaframework/base/services/core/JAVA/com/Android/server/am/AppErrors.java
class AppErrors {
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);
if (mService.mController != null) {
try {
// 0 == continue, -1 = kill process immediately
int res = mService.mController.appEarlyNotResponding(
app.processName, app.pid, annotation);
if (res < 0 && app.pid != MY_PID) {
app.kill("anr", true);
}
} catch (RemoteException e) {
mService.mController = null;
Watchdog.getInstance().setActivityController(null);
}
}
long anrTime = SystemClock.uptimeMillis();
if (ActivityManagerService.MONITOR_CPU_USAGE) {
mService.updateCpuStatsNow();
}
// Unless configured otherwise, swallow ANRs in background processes & kill the process.
boolean showBackground = Settings.Secure.getInt(mContext.getContentResolver(),
Settings.Secure.ANR_SHOW_BACKGROUND, 0) != 0;
boolean isSilentANR;
synchronized (mService) {
// PowerManager.reboot() can block for a long time, so ignore ANRs while shutting down.
if (mService.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;
} else if (app.killedByAm) {
Slog.i(TAG, "App already killed by AM skipping ANR: " + app + " " + annotation);
return;
} else if (app.killed) {
Slog.i(TAG, "Skipping died app ANR: " + app + " " + annotation);
return;
}
// In case we come through here for the same app before completing
// this one, mark as anring now so we will bail out.
app.notResponding = true;
// 記錄ANR到event log
EventLog.writeEvent(EventLogTags.AM_ANR, app.userId, app.pid,
app.processName, app.info.flags, annotation);
// Dump thread traces as quickly as we can, starting with "interesting" processes.
firstPids.add(app.pid);
// Don't dump other PIDs if it's a background ANR
isSilentANR = !showBackground && !isInterestingForBackgroundTraces(app);
if (!isSilentANR) {
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 = mService.mLruProcesses.size() - 1; i >= 0; i--) {
ProcessRecord r = mService.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);
if (DEBUG_ANR) Slog.i(TAG, "Adding persistent proc: " + r);
} else if (r.treatLikeActivity) {
firstPids.add(pid);
if (DEBUG_ANR) Slog.i(TAG, "Adding likely IME: " + r);
} else {
lastPids.put(pid, Boolean.TRUE);
if (DEBUG_ANR) Slog.i(TAG, "Adding ANR proc: " + r);
}
}
}
}
}
}
// 記錄ANR 到 main log
StringBuilder info = new StringBuilder();
info.setLength(0);
info.append("ANR in ").append(app.processName); //例如:ANR in com.xxxx.moblie (進程名)
if (activity != null && activity.shortComponentName != null) {
info.append(" (").append(activity.shortComponentName).append(")");//例如:(com.xxxx.moblie/.ui.MainActivity)
}
info.append("n");//換行
info.append("PID: ").append(app.pid).append("n");//記錄進程id
if (annotation != null) {
info.append("Reason: ").append(annotation).append("n");
}
if (parent != null && parent != activity) {
info.append("Parent: ").append(parent.shortComponentName).append("n");
}
ProcessCpuTracker processCpuTracker = new ProcessCpuTracker(true);
// don't dump native PIDs for background ANRs unless it is the process of interest
String[] nativeProcs = null;
if (isSilentANR) {
for (int i = 0; i < NATIVE_STACKS_OF_INTEREST.length; i++) {
if (NATIVE_STACKS_OF_INTEREST[i].equals(app.processName)) {
nativeProcs = new String[] { app.processName };
break;
}
}
} else {
nativeProcs = NATIVE_STACKS_OF_INTEREST;
}
int[] pids = nativeProcs == null ? null : Process.getPidsForCommands(nativeProcs);
ArrayList<Integer> nativePids = null;
if (pids != null) {
nativePids = new ArrayList<Integer>(pids.length);
for (int i : pids) {
nativePids.add(i);
}
}
// For background ANRs, don't pass the ProcessCpuTracker to
// avoid spending 1/2 second collecting stats to rank lastPids.
File tracesFile = ActivityManagerService.dumpStackTraces(
true, firstPids,
(isSilentANR) ? null : processCpuTracker,
(isSilentANR) ? null : lastPids,
nativePids);
String cpuInfo = null;
if (ActivityManagerService.MONITOR_CPU_USAGE) {
mService.updateCpuStatsNow();
synchronized (mService.mProcessCpuTracker) {
cpuInfo = mService.mProcessCpuTracker.printCurrentState(anrTime);
}
info.append(processCpuTracker.printCurrentLoad());
info.append(cpuInfo);
}
info.append(processCpuTracker.printCurrentState(anrTime));
//將ANR相關的錯誤日志信息打印出來
Slog.e(TAG, info.toString());
...省略...
}
通過上面的代碼我們知道,當ANR發生的時候,會將ANR記錄到event log和main log中。
三、查看events_log(如果沒有找到該文件可以跳過這一步)
查看mobilelog文件夾下的events_log,從日志中搜索關鍵字:am_anr,找到出現ANR的時間點、進程PID、ANR類型。
如日志:
07-20 15:36:36.472 1000 1520 1597 I am_anr : [0,1480,com.xxxx.moblie,952680005,Input dispatching timed out (AppWindowToken{da8f666 token=Token{5501f51 ActivityRecord{15c5c78 u0 com.xxxx.moblie/.ui.MainActivity t3862}}}, Waiting because no window has focus but there is a focused application that may eventually add a window when it finishes starting up.)]
從上面的log我們可以看出: 應用com.xxxx.moblie 在07-20 15:36:36.472時間,發生了一次KeyDispatchTimeout類型的ANR,它的進程號是1480.
把關鍵的信息整理一下:
- ANR時間:07-20 15:36:36.472
- 進程pid:1480
- 進程名:com.xxxx.moblie
- ANR類型:KeyDispatchTimeout
我們已經知道了發生KeyDispatchTimeout的ANR是因為 input事件在5秒內沒有處理完成。那么在這個時間07-20 15:36:36.472 的前5秒,也就是(15:36:30 ~15:36:31)時間段左右程序到底做了什么事情?這個簡單,因為我們已經知道pid了,再搜索一下pid = 1480的日志.這些日志表示該進程所運行的軌跡,關鍵的日志如下:
07-20 15:36:29.749 10102 1480 1737 D moblie-Application: [Thread:17329] receive an intent from server, action=com.ttt.push.RECEIVE_MESSAGE
07-20 15:36:30.136 10102 1480 1737 D moblie-Application: receiving an empty message, drop
07-20 15:36:35.791 10102 1480 1766 I Adreno : QUALCOMM build : 9c9b012, I92eb381bc9
07-20 15:36:35.791 10102 1480 1766 I Adreno : Build Date : 12/31/17
07-20 15:36:35.791 10102 1480 1766 I Adreno : OpenGL ES Shader Compiler Version: EV031.22.00.01
07-20 15:36:35.791 10102 1480 1766 I Adreno : Local Branch :
07-20 15:36:35.791 10102 1480 1766 I Adreno : Remote Branch : refs/tags/AU_linux_ANDROID_LA.UM.6.4.R1.08.00.00.309.049
07-20 15:36:35.791 10102 1480 1766 I Adreno : Remote Branch : NONE
07-20 15:36:35.791 10102 1480 1766 I Adreno : Reconstruct Branch : NOTHING
07-20 15:36:35.826 10102 1480 1766 I vndksupport: sphal namespace is not configured for this process. Loading /vendor/lib64/hw/gralloc.msm8998.so from the current namespace instead.
07-20 15:36:36.682 10102 1480 1480 W ViewRootImpl[MainActivity]: Cancelling event due to no window focus: KeyEvent { action=ACTION_UP, keyCode=KEYCODE_PERIOD, scanCode=0, metaState=0, flags=0x28, repeatCount=0, eventTime=16099429, downTime=16099429, deviceId=-1, source=0x101 }
從上面我們可以知道,在時間 07-20 15:36:29.749 程序收到了一個action消息。
07-20 15:36:29.749 10102 1480 1737 D moblie-Application: [Thread:17329] receive an intent from server, action=com.ttt.push.RECEIVE_MESSAGE。
原來是應用com.xxxx.moblie 收到了一個推送消息(com.ttt.push.RECEIVE_MESSAGE)導致了阻塞,我們再串聯一下目前所獲取到的信息:在時間07-20 15:36:29.749 應用com.xxxx.moblie 收到了一下推送信息action=com.ttt.push.RECEIVE_MESSAGE發生阻塞,5秒后發生了KeyDispatchTimeout的ANR。
四、查看main_log日志信息
在分析ANR的時候,我們首先要確認是不是當時CPU很緊張、各路APP都在搶占資源,CPU無法及時響應最終導致了ANR?為了排查這種情況,我們就需要獲取ANR發生時候的CPU狀態參數。
1、接下來我們來看一個ANR模擬日志案例
07-20 15:36:58.711 1000 1520 1597 E ActivityManager: ANR in com.xxxx.moblie (com.xxxx.moblie/.ui.MainActivity) (關鍵字ANR in + 進程名 + Activity名稱)
07-20 15:36:58.711 1000 1520 1597 E ActivityManager: PID: 1480 (進程pid)
07-20 15:36:58.711 1000 1520 1597 E ActivityManager: Reason: Input dispatching timed out (AppWindowToken{da8f666 token=Token{5501f51 ActivityRecord{15c5c78 u0 com.xxxx.moblie/.ui.MainActivity t3862}}}, Waiting because no window has focus but there is a focused application that may eventually add a window when it finishes starting up.)(ANR的原因,輸入分發超時)
07-20 15:36:58.711 1000 1520 1597 E ActivityManager: Load: 0.0 / 0.0 / 0.0 (Load表明是1分鐘,5分鐘,15分鐘CPU的負載)
07-20 15:36:58.711 1000 1520 1597 E ActivityManager: CPU usage from 20ms to 20286ms later (2018-07-20 15:36:36.170 to 2018-07-20 15:36:56.436):
07-20 15:36:58.711 1000 1520 1597 E ActivityManager: 42% 6774/pressure: 41% user + 1.4% kernel / faults: 168 minor
07-20 15:36:58.711 1000 1520 1597 E ActivityManager: 34% 142/kswapd0: 0% user + 34% kernel
07-20 15:36:58.711 1000 1520 1597 E ActivityManager: 31% 1520/system_server: 13% user + 18% kernel / faults: 58724 minor 1585 major
07-20 15:36:58.711 1000 1520 1597 E ActivityManager: 13% 29901/com.ss.android.article.news: 7.7% user + 6% kernel / faults: 56007 minor 2446 major
07-20 15:36:58.711 1000 1520 1597 E ActivityManager: 13% 32638/com.android.quicksearchbox: 9.4% user + 3.8% kernel / faults: 48999 minor 1540 major
07-20 15:36:58.711 1000 1520 1597 E ActivityManager: 11% (CPU的使用率)1480/com.xxxx.moblie: 5.2%(用戶態的使用率) user + (內核態的使用率) 6.3% kernel / faults: 76401 minor 2422 major
07-20 15:36:58.711 1000 1520 1597 E ActivityManager: 8.2% 21000/kworker/u16:12: 0% user + 8.2% kernel
07-20 15:36:58.711 1000 1520 1597 E ActivityManager: 0.8% 724/mtd: 0% user + 0.8% kernel / faults: 1561 minor 9 major
07-20 15:36:58.711 1000 1520 1597 E ActivityManager: 8% 29704/kworker/u16:8: 0% user + 8% kernel
07-20 15:36:58.711 1000 1520 1597 E ActivityManager: 7.9% 24391/kworker/u16:18: 0% user + 7.9% kernel
07-20 15:36:58.711 1000 1520 1597 E ActivityManager: 7.1% 30656/kworker/u16:14: 0% user + 7.1% kernel
07-20 15:36:58.711 1000 1520 1597 E ActivityManager: 7.1% 9998/kworker/u16:4: 0% user + 7.1% kernel
通過上面所提供的案例我們可以分析出以下幾點:
- ANR發生的位置是:com.xxxx.moblie/.ui.MainActivity
- com.xxxx.moblie 占用了11%的CPU,CPU的使用率并不是很高,基本可以排除CPU負載的原因
- Reason提示我們是輸入分發超時導致的ANR
2、下面所提供的是一個ANR的真實日志案例
10-09 19:35:22.124 940 968 E ActivityManager: ANR in com.example.anrtest (com.example.anrtest/.MainActivity) // 記錄ANR+進程名+Activity名稱
10-09 19:35:22.124 940 968 E ActivityManager: PID: 8390 //記錄進程ID
10-09 19:35:22.124 940 968 E ActivityManager: Reason: 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: 28. Wait queue head age: 5517.5ms.)(ANR的原因,輸入分發超時)
10-09 19:35:22.124 940 968 E ActivityManager: Load: 2.52 / 2.57 / 2.73
10-09 19:35:22.124 940 968 E ActivityManager: CPU usage from 99984ms to 0ms ago (2022-10-09 19:33:39.209 to 2022-10-09 19:35:19.194):
10-09 19:35:22.124 940 968 E ActivityManager: 25% 445/surfaceflinger: 14% user + 11% kernel / faults: 11962 minor
10-09 19:35:22.124 940 968 E ActivityManager: 11% 394/[email protected]: 2.9% user + 8.2% kernel / faults: 1 minor
10-09 19:35:22.124 940 968 E ActivityManager: 10% 2101/com.leapmotor.appcenter: 7.8% user + 3.1% kernel / faults: 926 minor
10-09 19:35:22.124 940 968 E ActivityManager: 3.2% 1961/com.iflytek.cutefly.speechclient.hmi: 2.5% user + 0.7% kernel / faults: 2111 minor
10-09 19:35:22.124 940 968 E ActivityManager: 1.8% 386/[email protected]: 0.2% user + 1.6% kernel10-09 19:35:22.124 940 968 E ActivityManager: 0.9% 940/system_server: 0.6% user + 0.3% kernel / faults: 5334 minor10-09 19:35:22.124 940 968 E ActivityManager: 0.7% 440/audIOServer: 0.3% user + 0.3% kernel
10-09 19:35:22.124 940 968 E ActivityManager: 0.3% 277/apr_vm_cb_threa: 0% user + 0.3% kernel
10-09 19:35:22.124 940 968 E ActivityManager: 0.3% 544/leap_uhab: 0% user + 0.2% kernel / faults: 20 minor
10-09 19:35:22.124 940 968 E ActivityManager: 0.3% 5219/com.leapmotor.leapmotorsoscall: 0.1% user + 0.1% kernel
10-09 19:35:22.124 940 968 E ActivityManager: 0.2% 2367/com.leapmotor.multimedia: 0% user + 0.2% kernel / faults: 9 minor
10-09 19:35:22.124 940 968 E ActivityManager: 0.2% 8215/kworker/2:3: 0% user + 0.2% kernel
10-09 19:35:22.124 940 968 E ActivityManager: 0.2% 3992/adbd: 0% user + 0.2% kernel / faults: 46652 minor
10-09 19:35:22.124 940 968 E ActivityManager: 0.2% 7786/com.ebanma.tinyapp: 0.2% user + 0% kernel / faults: 557 minor
10-09 19:35:22.124 940 968 E ActivityManager: 0.2% 7895/com.ebanma.tinyapp:DataCenterService: 0.2% user + 0% kernel / faults: 463 minor
10-09 19:35:22.124 940 968 E ActivityManager: 0.1% 543/leap_systemsdk_service: 0% user + 0.1% kernel
10-09 19:35:22.124 940 968 E ActivityManager: 0.1% 1392/com.leapmotor.cameraaround: 0% user + 0.1% kernel
10-09 19:35:22.124 940 968 E ActivityManager: 0.1% 410/leap_vsomeip_route: 0.1% user + 0% kernel
10-09 19:35:22.124 940 968 E ActivityManager: 0.1% 3554/com.leapmotor.driverecord:emergency: 0% user + 0% kernel
10-09 19:35:22.124 940 968 E ActivityManager: 0.1% 411/leap_camera_around: 0% user + 0.1% kernel
10-09 19:35:22.124 940 968 E ActivityManager: 0.1% 2915/com.leapmotor.systemupdate: 0% user + 0% kernel / faults: 5 minor
10-09 19:35:22.124 940 968 E ActivityManager: 0.1% 9/rcu_preempt: 0% user + 0.1% kernel
10-09 19:35:22.124 940 968 E ActivityManager: 0.1% 412/leap_camera_face: 0% user + 0.1% kernel
10-09 19:35:22.124 940 968 E ActivityManager: 0.1% 413/leap_camera_front: 0% user + 0.1% kernel
10-09 19:35:22.124 940 968 E ActivityManager: 0.1% 2021/com.leapmotor.facevideo: 0% user + 0% kernel
10-09 19:35:22.124 940 968 E ActivityManager: 0.1% 2554/com.leapmotor.phone: 0% user + 0.1% kernel / faults: 10 minor
10-09 19:35:22.124 940 968 E ActivityManager: 0.1% 1916/com.leapmotor.log: 0% user + 0% kernel / faults: 2 minor
10-09 19:35:22.124 940 968 E ActivityManager: 0.1% 2188/com.leapmotor.camera:front_encode: 0% user + 0% kernel
10-09 19:35:22.124 940 968 E ActivityManager: 0.1% 2211/com.leapmotor.camera:around_encode: 0% user + 0% kernel
10-09 19:35:22.124 940 968 E ActivityManager: 0.1% 3541/com.leapmotor.driverecord:trip: 0% user + 0% kernel
10-09 19:35:22.124 940 968 E ActivityManager: 0% 285/logd: 0% user + 0% kernel / faults: 3 minor
10-09 19:35:22.124 940 968 E ActivityManager: 0% 325/ais_v4l2_proxy: 0% user + 0% kernel
10-09 19:35:22.124 940 968 E ActivityManager: 0% 541/leap_shutdown: 0% user + 0% kernel
10-09 19:35:22.124 940 968 E ActivityManager: 0% 2243/com.leapmotor.camera:front_push_encode: 0% user + 0% kernel
10-09 19:35:22.124 940 968 E ActivityManager: 0% 1199/com.android.systemui: 0% user + 0% kernel / faults: 576 minor
10-09 19:35:22.124 940 968 E ActivityManager: 0% 3492/com.leapmotor.driverecord: 0% user + 0% kernel
10-09 19:35:22.124 940 968 E ActivityManager: 0% 251/vlog: 0% user + 0% kernel
10-09 19:35:22.124 940 968 E ActivityManager: 0% 560/installd: 0% user + 0% kernel / faults: 8 minor
10-09 19:35:22.124 940 968 E ActivityManager: 0% 4106/kworker/u8:0: 0% user + 0% kernel
10-09 19:35:22.124 940 968 E ActivityManager: 0% 6191/installer: 0% user + 0% kernel / faults: 295 minor
10-09 19:35:22.124 940 968 E ActivityManager: 0% 8/ksoftirqd/0: 0% user + 0% kernel
10-09 19:35:22.124 940 968 E ActivityManager: 0% 18/ksoftirqd/1: 0% user + 0% kernel
10-09 19:35:22.124 940 968 E ActivityManager: 0% 1131/com.android.car: 0% user + 0% kernel / faults: 553 minor
10-09 19:35:22.124 940 968 E ActivityManager: 0% 2134/com.leapmotor.bt:bt_service: 0% user + 0% kernel
10-09 19:35:22.124 940 968 E ActivityManager: 0% 7818/kworker/u9:0: 0% user + 0% kernel
10-09 19:35:22.124 940 968 E ActivityManager: 0% 24/ksoftirqd/2: 0% user + 0% kernel
10-09 19:35:22.124 940 968 E ActivityManager: 0% 512/leap_logcat: 0% user + 0% kernel
10-09 19:35:22.124 940 968 E ActivityManager: 0% 10/rcu_sched: 0% user + 0% kernel
10-09 19:35:22.124 940 968 E ActivityManager: 0% 30/ksoftirqd/3: 0% user + 0% kernel
10-09 19:35:22.124 940 968 E ActivityManager: 0% 70/system: 0% user + 0% kernel
10-09 19:35:22.124 940 968 E ActivityManager: 0% 240/kworker/u8:10: 0% user + 0% kernel
10-09 19:35:22.124 940 968 E ActivityManager: 0% 281/jbd2/vdb-8: 0% user + 0% kernel
10-09 19:35:22.124 940 968 E ActivityManager: 0% 286/servicemanager: 0% user + 0% kernel
10-09 19:35:22.124 940 968 E ActivityManager: 0% 287/hwservicemanager: 0% user + 0% kernel
10-09 19:35:22.124 940 968 E ActivityManager: 0% 330/zygote64: 0% user + 0% kernel / faults: 153 minor
10-09 19:35:22.124 940 968 E ActivityManager: 0% 409/[email protected]: 0% user + 0% kernel / faults: 37 minor
10-09 19:35:22.124 940 968 E ActivityManager: 0% 542/leap_vsomeip_qnx_heart: 0% user + 0% kernel / faults: 3 minor10-09 19:35:22.124 940 968 E ActivityManager: 0% 654/msm_irqbalance: 0% user + 0% kernel
10-09 19:35:22.124 940 968 E ActivityManager: 0% 677/ipacm: 0% user + 0% kernel
10-09 19:35:22.124 940 968 E ActivityManager: 0% 1366/.dataservices: 0% user + 0% kernel / faults: 3 minor
10-09 19:35:22.124 940 968 E ActivityManager: 0% 2665/dmesg: 0% user + 0% kernel
10-09 19:35:22.124 940 968 E ActivityManager: 0% 2893/android.process.acore: 0% user + 0% kernel / faults: 35 minor
10-09 19:35:22.124 2101 2120 I motor.appcente: Wrote stack traces to '[tombstoned]'
10-09 19:35:22.125 940 969 W ActivityManager: Force finishing activity com.example.anrtest/.MainActivity
10-09 19:35:22.127 940 969 I ActivityManager: saveTopActivity mTmpTop=com.example.anrtest/com.example.anrtest.MainActivity
通過上面所提供的案例我們可以分析出以下幾點:
- ANR發生的位置是:com.example.anrtest/.MainActivity
- CPU的使用率都不是很高,基本可以排除CPU負載的原因
- Reason提示我們是輸入分發超時導致的ANR
通過上面幾點我們雖然排除了CPU過度負載的可能,但我們并不能準確定位出ANR的確切位置,要想準確定位出ANR發生的確切位置,就要借助系統為了解決ANR問題而提供的終極大殺器——traces.txt文件了。
五、 traces.txt 文件分析
當APP不響應、響應慢了、或者WatchDog的監視沒有得到回應時,系統就會dump出一個traces.txt文件,存放在文件目錄:/data/anr/文件夾中,通過traces文件,我們可以拿到線程名、堆棧信息、線程當前狀態、binder call等信息。
我們可以通過adb命令獲取到該文件夾下面的所有traces文件:adb pull /data/anr
trace:
Cmd line:com.xxxx.moblie
"main" prio=5 tid=1 Runnable
| group="main" sCount=0 dsCount=0 obj=0x73bcc7d0 self=0x7f20814c00
| sysTid=20176 nice=-10 cgrp=default sched=0/0 handle=0x7f251349b0
| state=R schedstat=( 0 0 0 ) utm=12 stm=3 core=5 HZ=100
| stack=0x7fdb75e000-0x7fdb760000 stackSize=8MB
| held mutexes= "mutator lock"(shared held)
// java 堆棧調用信息,可以查看調用的關系,定位到具體位置
at ttt.push.InterceptorProxy.addMiuiApplication(InterceptorProxy.java:77)
at ttt.push.InterceptorProxy.create(InterceptorProxy.java:59)
at android.app.Activity.onCreate(Activity.java:1041)
at miui.app.Activity.onCreate(SourceFile:47)
at com.xxxx.moblie.ui.b.onCreate(SourceFile:172)
at com.xxxx.moblie.ui.MainActivity.onCreate(SourceFile:68)
at android.app.Activity.performCreate(Activity.java:7050)
at android.app.Instrumentation.callActivityOnCreate(Instrumentation.java:1214)
at android.app.ActivityThread.performLaunchActivity(ActivityThread.java:2807)
at android.app.ActivityThread.handleLaunchActivity(ActivityThread.java:2929)
at android.app.ActivityThread.-wrap11(ActivityThread.java:-1)
at android.app.ActivityThread$H.handleMessage(ActivityThread.java:1618)
at android.os.Handler.dispatchMessage(Handler.java:105)
at android.os.Looper.loop(Looper.java:171)
at android.app.ActivityThread.main(ActivityThread.java:6699)
at java.lang.reflect.Method.invoke(Native method)
at com.android.internal.os.Zygote$MethodAndArgsCaller.run(Zygote.java:246)
at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:783)
這里詳細解析一下traces.txt里面的一些字段,看看它到底能給我們提供什么信息.
- main:main標識是主線程,如果是線程,那么命名成“Thread-X”的格式,x表示線程id,逐步遞增。
- prio:線程優先級,默認是5
- tid:tid不是線程的id,是線程唯一標識ID
- group:是線程組名稱
- sCount:該線程被掛起的次數
- dsCount:是線程被調試器掛起的次數
- obj:對象地址
- self:該線程Native的地址
- sysTid:是線程號(主線程的線程號和進程號相同)
- nice:是線程的調度優先級
- sched:分別標志了線程的調度策略和優先級
- cgrp:調度歸屬組
- handle:線程處理函數的地址。
- state:是調度狀態
- schedstat:從 /proc/[pid]/task/[tid]/schedstat讀出,三個值分別表示線程在cpu上執行的時間、線程的等待時間和線程執行的時間片長度,不支持這項信息的三個值都是0;
- utm:是線程用戶態下使用的時間值(單位是jiffies)
- stm:是內核態下的調度時間值
- core:是最后執行這個線程的cpu核的序號。
Java的堆棧信息是我們最關心的,它能夠定位到具體位置。從上面的traces,我們可以判斷ttt.push.InterceptorProxy.addMiuiApplicationInterceptorProxy.java:77 導致了com.xxxx.moblie發生了ANR。這時候可以對著源碼查看,找到出問題,并且解決它。
接下來再看一個真實的導致ANR的trace案例:
//開頭顯示進程號、ANR發生的時間點和進程名稱
----- pid 4972 at 2022-10-09 16:45:41 -----
Cmd line: com.example.anrtest
...省略...
DALVIK THREADS (14)://以下是各個線程的函數堆棧信息
//依次是:線程名(后面標識有daemon說明是個守護線程)、線程優先級、線程號、線程當前狀態(TIMED_WAIT或SUSPENDED在anr時很常見)
"Signal Catcher" daemon prio=5 tid=3 Runnable
//依次是:線程組名稱、suspendCount個數、debugSuspendCount個數、標記,線程的Java對象地址、線程的Native對象地址
| group="system" sCount=0 dsCount=0 flags=0 obj=0x15980100 self=0x7322e16400
//sysTid是線程號,主線程的線程號和進程號相同
| sysTid=4978 nice=0 cgrp=default sched=0/0 handle=0x731c3304f0
| state=R schedstat=( 5583230 6778645 10 ) utm=0 stm=0 core=3 HZ=100
| stack=0x731c235000-0x731c237000 stackSize=1009KB
| held mutexes= "mutator lock"(shared held)
//“Signal Catcher”負責接收和處理kernel發送的各種信號,例如SIGNAL_QUIT、SIGNAL_USR1等就是被該線程
//接收到,這個文件的內容就是由該線程負責輸出的,可以看到它的狀態是RUNNABLE,不過此線程也不需要關心
...省略...
//主線程,當前處于休眠狀態
"main" prio=5 tid=1 Sleeping
| group="main" sCount=1 dsCount=0 flags=1 obj=0x73e64b08 self=0x7322e14c00
| sysTid=4972 nice=-10 cgrp=default sched=0/0 handle=0x73a88cc548
| state=S schedstat=( 618097798 184039398 700 ) utm=56 stm=5 core=3 HZ=100
| stack=0x7fd05f2000-0x7fd05f4000 stackSize=8MB
| held mutexes=
at java.lang.Thread.sleep(Native method)
- sleeping on <0x0d9c45cc> (a java.lang.Object)
at java.lang.Thread.sleep(Thread.java:373)
- locked <0x0d9c45cc> (a java.lang.Object)
at java.lang.Thread.sleep(Thread.java:314)
at android.os.SystemClock.sleep(SystemClock.java:127)
at com.example.anrtest.MainActivity$1.onClick(MainActivity.java:57)
at android.view.View.performClick(View.java:6597)
at android.view.View.performClickInternal(View.java:6574)
at android.view.View.access$3100(View.java:778)
at android.view.View$PerformClick.run(View.java:25885)
at android.os.Handler.handleCallback(Handler.java:873)
at android.os.Handler.dispatchMessage(Handler.java:99)
at android.os.Looper.loop(Looper.java:193)
at android.app.ActivityThread.main(ActivityThread.java:6718)
at java.lang.reflect.Method.invoke(Native method)
at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:493)
at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:858)
...省略...
"Jit thread pool worker thread 0" daemon prio=5 tid=2 Native
| group="main" sCount=1 dsCount=0 flags=1 obj=0x15980000 self=0x731c029000
| sysTid=4977 nice=9 cgrp=default sched=0/0 handle=0x731c4314f0
| state=S schedstat=( 122669387 79479997 188 ) utm=8 stm=3 core=3 HZ=100
| stack=0x731c333000-0x731c335000 stackSize=1021KB
| held mutexes=
...省略...
//Binder線程是進程的線程池中用來處理binder請求的線程
"Binder:4972_1" prio=5 tid=9 Native
| group="main" sCount=1 dsCount=0 flags=1 obj=0x159829a0 self=0x731a60d000
| sysTid=4984 nice=0 cgrp=default sched=0/0 handle=0x73099b34f0
| state=S schedstat=( 12586983 41079166 22 ) utm=1 stm=0 core=3 HZ=100
| stack=0x73098b8000-0x73098ba000 stackSize=1009KB
| held mutexes=
...省略...
六、ANR分析流程總結
總結一下上面我們分析ANR的主體流程:
1、首先我們搜索am_anr,找到出現ANR的時間點、進程PID、ANR類型、然后再找搜索PID,找前5秒左右的日志。
2、過濾ANR IN 查看CPU信息
3、接著查看traces.txt,找到java的堆棧信息定位代碼位置,最后查看源碼,分析與解決問題。
到這里,通過上面三個步驟我們基本就能定位出來大部分ANR的來龍去脈了。
我在接下來的第六步和第七步還繼續提供了多個ANR案例供大家參考分析,有興趣的可以看著。
七、ANR 案例整理
1、主線程被其他線程lock,導致死鎖
waiting on <0x1cd570> (a android.os.MessageQueue)
DALVIK THREADS:
"main" prio=5 tid=3 TIMED_WAIT
| group="main" sCount=1 dsCount=0 s=0 obj=0x400143a8
| sysTid=691 nice=0 sched=0/0 handle=-1091117924
at java.lang.Object.wait(Native Method)
- waiting on <0x1cd570> (a android.os.MessageQueue)
at java.lang.Object.wait(Object.java:195)
at android.os.MessageQueue.next(MessageQueue.java:144)
at android.os.Looper.loop(Looper.java:110)
at android.app.ActivityThread.main(ActivityThread.java:3742)
at java.lang.reflect.Method.invokeNative(Native Method)
at java.lang.reflect.Method.invoke(Method.java:515)
at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:739)
at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:497)
at dalvik.system.NativeStart.main(Native Method)
"Binder Thread #3" prio=5 tid=15 NATIVE
| group="main" sCount=1 dsCount=0 s=0 obj=0x434e7758
| sysTid=734 nice=0 sched=0/0 handle=1733632
at dalvik.system.NativeStart.run(Native Method)
"Binder Thread #2" prio=5 tid=13 NATIVE
| group="main" sCount=1 dsCount=0 s=0 obj=0x1cd570
| sysTid=696 nice=0 sched=0/0 handle=1369840
at dalvik.system.NativeStart.run(Native Method)
"Binder Thread #1" prio=5 tid=11 NATIVE
| group="main" sCount=1 dsCount=0 s=0 obj=0x433aca10
| sysTid=695 nice=0 sched=0/0 handle=1367448
at dalvik.system.NativeStart.run(Native Method)
----- end 691 -----
2、主線程做耗時的操作:比如數據庫讀寫。
"main" prio=5 tid=1 Native
held mutexes=
kernel: (couldn't read /proc/self/task/11003/stack)
native: #00 pc 000492a4 /system/lib/libc.so (nanosleep+12)
native: #01 pc 0002dc21 /system/lib/libc.so (usleep+52)
native: #02 pc 00009cab /system/lib/libsqlite.so (???)
native: #03 pc 00011119 /system/lib/libsqlite.so (???)
native: #04 pc 00016455 /system/lib/libsqlite.so (???)
native: #16 pc 0000fa29 /system/lib/libsqlite.so (???)
native: #17 pc 0000fad7 /system/lib/libsqlite.so (sqlite3_prepare16_v2+14)
native: #18 pc 0007f671 /system/lib/libandroid_runtime.so (???)
native: #19 pc 002b4721 /system/framework/arm/boot-framework.oat (Java_android_database_sqlite_SQLiteConnection_nativePrepareStatement__JLjava_lang_String_2+116)
at android.database.sqlite.SQLiteConnection.setWalModeFromConfiguration(SQLiteConnection.java:294)
at android.database.sqlite.SQLiteConnection.open(SQLiteConnection.java:215)
at android.database.sqlite.SQLiteConnection.open(SQLiteConnection.java:193)
at android.database.sqlite.SQLiteConnectionPool.openConnectionLocked(SQLiteConnectionPool.java:463)
at android.database.sqlite.SQLiteConnectionPool.open(SQLiteConnectionPool.java:185)
at android.database.sqlite.SQLiteConnectionPool.open(SQLiteConnectionPool.java:177)
at android.database.sqlite.SQLiteDatabase.openInner(SQLiteDatabase.java:808)
locked <0x0db193bf> (a java.lang.Object)
at android.database.sqlite.SQLiteDatabase.open(SQLiteDatabase.java:793)
at android.database.sqlite.SQLiteDatabase.openDatabase(SQLiteDatabase.java:696)
at android.app.ContextImpl.openOrCreateDatabase(ContextImpl.java:690)
at android.content.ContextWrapper.openOrCreateDatabase(ContextWrapper.java:299)
at android.database.sqlite.SQLiteOpenHelper.getDatabaseLocked(SQLiteOpenHelper.java:223)
at android.database.sqlite.SQLiteOpenHelper.getWritableDatabase(SQLiteOpenHelper.java:163)
locked <0x045a4a8c> (a com.xxxx.video.common.data.DataBaseHelper)
at com.xxxx.video.common.data.DataBaseoRM.<init>(DataBaseORM.java:46)
at com.xxxx.video.common.data.DataBaseORM.getInstance(DataBaseORM.java:53)
locked <0x017095d5> (a java.lang.Class<com.xxxx.video.common.data.DataBaseORM>)
3、binder數據量過大
07-21 04:43:21.573 1000 1488 12756 E Binder : Unreasonably large binder reply buffer: on android.content.pm.BaseParceledListSlice$1@770c74f calling 1 size 388568 (data: 1, 32, 7274595)
07-21 04:43:21.573 1000 1488 12756 E Binder : android.util.Log$TerribleFailure: Unreasonably large binder reply buffer: on android.content.pm.BaseParceledListSlice$1@770c74f calling 1 size 388568 (data: 1, 32, 7274595)
07-21 04:43:21.607 1000 1488 2951 E Binder : Unreasonably large binder reply buffer: on android.content.pm.BaseParceledListSlice$1@770c74f calling 1 size 211848 (data: 1, 23, 7274595)
07-21 04:43:21.607 1000 1488 2951 E Binder : android.util.Log$TerribleFailure: Unreasonably large binder reply buffer: on android.content.pm.BaseParceledListSlice$1@770c74f calling 1 size 211848 (data: 1, 23, 7274595)
07-21 04:43:21.662 1000 1488 6258 E Binder : Unreasonably large binder reply buffer: on android.content.pm.BaseParceledListSlice$1@770c74f calling 1 size 259300 (data: 1, 33, 7274595)
4、binder 通信失敗
07-21 06:04:35.580 <6>[32837.690321] binder: 1698:2362 transaction failed 29189/-3, size 100-0 line 3042
07-21 06:04:35.594 <6>[32837.704042] binder: 1765:4071 transaction failed 29189/-3, size 76-0 line 3042
07-21 06:04:35.899 <6>[32838.009132] binder: 1765:4067 transaction failed 29189/-3, size 224-8 line 3042
07-21 06:04:36.018 <6>[32838.128903] binder: 1765:2397 transaction failed 29189/-22, size 348-0 line 2916
八、模擬觸發ANR事件,獲取trace文件
以下的幾個案例,都是我通過代碼故意觸發ANR所產生的trace文件。
1、輸入的事件在5秒內沒有被響應,主線程被阻塞。
輸入事件5s沒有響應,如onClick事件。這是anr問題的主要類型,一般開發者不會犯這樣的錯,凡是耗時的操作都另開線程處理,如果疏忽了看看自己的代碼就知道怎么處理。
(1)模擬觸發ANR:
Java
findViewById(R.id.btn_test).setOnClickListener(new View.OnClickListener() {
@Override
public void onClick(View v) {
SystemClock.sleep(40000);//故意響應超時導致ANR
}
});
(2)對應的Trace文件關鍵日志:
DALVIK THREADS (14): //虛擬機線程被阻塞
"Signal Catcher" daemon prio=5 tid=3 Runnable
| group="system" sCount=0 dsCount=0 flags=0 obj=0x15980100 self=0x7322e16400
| sysTid=4978 nice=0 cgrp=default sched=0/0 handle=0x731c3304f0
| state=R schedstat=( 5583230 6778645 10 ) utm=0 stm=0 core=3 HZ=100
| stack=0x731c235000-0x731c237000 stackSize=1009KB
| held mutexes= "mutator lock"(shared held)
"main" prio=5 tid=1 Sleeping //主線程被阻塞
| group="main" sCount=1 dsCount=0 flags=1 obj=0x73e64b08 self=0x7322e14c00
| sysTid=4972 nice=-10 cgrp=default sched=0/0 handle=0x73a88cc548
| state=S schedstat=( 618097798 184039398 700 ) utm=56 stm=5 core=3 HZ=100
| stack=0x7fd05f2000-0x7fd05f4000 stackSize=8MB
| held mutexes=
at java.lang.Thread.sleep(Native method)
- sleeping on <0x0d9c45cc> (a java.lang.Object)
at java.lang.Thread.sleep(Thread.java:373)
- locked <0x0d9c45cc> (a java.lang.Object)
at java.lang.Thread.sleep(Thread.java:314)
at android.os.SystemClock.sleep(SystemClock.java:127) //代碼被阻塞的關鍵位置
at com.example.anrtest.MainActivity$1.onClick(MainActivity.java:57) //按鈕的點擊事件
at android.view.View.performClick(View.java:6597)
at android.view.View.performClickInternal(View.java:6574)
at android.view.View.access$3100(View.java:778)
at android.view.View$PerformClick.run(View.java:25885)
at android.os.Handler.handleCallback(Handler.java:873)
at android.os.Handler.dispatchMessage(Handler.java:99)
at android.os.Looper.loop(Looper.java:193)
at android.app.ActivityThread.main(ActivityThread.java:6718)
at java.lang.reflect.Method.invoke(Native method)
at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:493)
at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:858)
2、廣播接收者的onReceive方法在10秒內沒有執行完畢。
BroadcastReceiver是在程序主線程運行,而且默認情況下BroadcastReceiver的運行時間為10s,所以不能有耗時操作,如果耗時超過10s就會導致anr,從traces文件log就可以看出onReceive不能進行耗時任務。
(1)模擬觸發ANR:
Java
IntentFilter intentFilter = new IntentFilter();
intentFilter.addAction("com.anr.test");
registerReceiver(new BroadcastReceiver() {
@Override
public void onReceive(Context context, Intent intent) {
SystemClock.sleep(40000);//故意響應超時導致ANR
}
}, intentFilter);
(2)對應的Trace文件關鍵日志:
DALVIK THREADS (14): //虛擬機線程被阻塞
"Signal Catcher" daemon prio=5 tid=3 Runnable
| group="system" sCount=0 dsCount=0 flags=0 obj=0x13100088 self=0x7322e16400
| sysTid=6639 nice=0 cgrp=default sched=0/0 handle=0x731c3304f0
| state=R schedstat=( 6547603 5577708 11 ) utm=0 stm=0 core=0 HZ=100
| stack=0x731c235000-0x731c237000 stackSize=1009KB
| held mutexes= "mutator lock"(shared held)
"main" prio=5 tid=1 Sleeping //主線程被阻塞
| group="main" sCount=1 dsCount=0 flags=1 obj=0x73e64b08 self=0x7322e14c00
| sysTid=6633 nice=-10 cgrp=default sched=0/0 handle=0x73a88cc548
| state=S schedstat=( 605006551 138044643 533 ) utm=56 stm=3 core=2 HZ=100
| stack=0x7fd05f2000-0x7fd05f4000 stackSize=8MB
| held mutexes=
at java.lang.Thread.sleep(Native method)
- sleeping on <0x08c05759> (a java.lang.Object)
at java.lang.Thread.sleep(Thread.java:373)
- locked <0x08c05759> (a java.lang.Object)
at java.lang.Thread.sleep(Thread.java:314)
at android.os.SystemClock.sleep(SystemClock.java:127) //代碼被阻塞的關鍵位置
at com.example.anrtest.MainActivity$3.onReceive(MainActivity.java:80) //廣播接收者的onReceive方法
at android.app.LoadedApk$ReceiverDispatcher$Args.lambda$getRunnable$0(LoadedApk.java:1391)
at android.app.-$$Lambda$LoadedApk$ReceiverDispatcher$Args$_BumDX2UKsnxLVrE6UJsJZkotuA.run(lambda:-1)
at android.os.Handler.handleCallback(Handler.java:873)
at android.os.Handler.dispatchMessage(Handler.java:99)
at android.os.Looper.loop(Looper.java:193)
at android.app.ActivityThread.main(ActivityThread.java:6718)
at java.lang.reflect.Method.invoke(Native method)
at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:493)
at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:858)
BroadcastReceiver是Android的消息組件,用來組件之間、應用之間的消息傳遞,生命周期太短也不能開子線程處理耗時任務,耗時任務一般轉交給IntentService或者JobIntentService去做。
3、服務Service沒有及時響應
Service是計算型組件,雖然在后臺運行,但是本質上它也跑在主線程,如果你的服務要做任何CPU密集型(如MP3播放)或阻塞(如網絡)操作,都要放在子線程中,否則耗時超過20s就會導致anr。下面我在onStartCommand方法中休眠40秒。
(1)模擬觸發ANR:
Java
@Override
public int onStartCommand(Intent intent, int flags, int startId) {
SystemClock.sleep(40000);//故意響應超時導致ANR
return super.onStartCommand(intent, flags, startId);
}
(2)對應的Trace文件關鍵日志:
DALVIK THREADS (13): //虛擬機線程被阻塞
"Signal Catcher" daemon prio=5 tid=3 Runnable
| group="system" sCount=0 dsCount=0 flags=0 obj=0x13940108 self=0x7322e16400
| sysTid=7658 nice=0 cgrp=default sched=0/0 handle=0x731c3304f0
| state=R schedstat=( 5995782 10695989 10 ) utm=0 stm=0 core=3 HZ=100
| stack=0x731c235000-0x731c237000 stackSize=1009KB
| held mutexes= "mutator lock"(shared held)
"main" prio=5 tid=1 Sleeping //主線程被阻塞
| group="main" sCount=1 dsCount=0 flags=1 obj=0x73e64b08 self=0x7322e14c00
| sysTid=7652 nice=-10 cgrp=default sched=0/0 handle=0x73a88cc548
| state=S schedstat=( 595004855 101962599 596 ) utm=40 stm=18 core=2 HZ=100
| stack=0x7fd05f2000-0x7fd05f4000 stackSize=8MB
| held mutexes=
at java.lang.Thread.sleep(Native method)
- sleeping on <0x0e096f2a> (a java.lang.Object)
at java.lang.Thread.sleep(Thread.java:373)
- locked <0x0e096f2a> (a java.lang.Object)
at java.lang.Thread.sleep(Thread.java:314)
at android.os.SystemClock.sleep(SystemClock.java:127) //代碼被阻塞的關鍵位置
at com.example.anrtest.ANRService.onStartCommand(ANRService.java:17) //服務的onStartCommand方法
at android.app.ActivityThread.handleServiceArgs(ActivityThread.java:3705)
at android.app.ActivityThread.access$1600(ActivityThread.java:200)
at android.app.ActivityThread$H.handleMessage(ActivityThread.java:1688)
at android.os.Handler.dispatchMessage(Handler.java:106)
at android.os.Looper.loop(Looper.java:193)
at android.app.ActivityThread.main(ActivityThread.java:6718)
at java.lang.reflect.Method.invoke(Native method)
at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:493)
at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:858)