admin管理员组

文章数量:1534209

前言

本文主要介绍anr问题一手分析、分类判断,归类后提case给平台处理。
不是针对应用开发的anr分析和优化处理。

anr问题分类

anr问题主要分为

1、input 无焦点anr
Reason: Input dispatching timed out (Application does not have a focused window)
2、input 有焦点anr
Reason: Input dispatching timed out (eadf99 net.zedge.android/net.zedge.android.activity.MainActivity (server) is not responding. Waited 13000ms for FocusEvent(hasFocus=true))

Reason: Input dispatching timed out (4843092 com.ubercab/com.ubercab.presidio.app.core.root.RootActivity (server) is not responding. Waited 13001ms for MotionEvent(deviceId=-1, eventTime=96940680000000, source=TRACKBALL, displayId=0, action=MOVE, actionButton=0x00000000, flags=0x00000000, metaState=0x00000000, buttonState=0x00000000, classification=NONE, edgeFlags=0x00000000, xPrecision=1.0, yPrecision=1.0, xCursorPosition=nan, yCursorPosition=nan, pointers=[0: (-1.0, -2.0)]), policyFlags=0x6b000000)
3、广播anr
Reason: Broadcast of Intent { act=com.google.firebase.INSTANCE_ID_EVENT flg=0x14 cmp=com.amulyam/com.google.firebase.iid.FirebaseInstanceIdInternalReceiver (has extras) }
4、service anr
Reason: executing service com.instagram.android/com.facebook.rti.push.service.FbnsService

目前只遇到过这几种anr情况,如果后续有碰到新的类型会更新。

Input dispatching anr组合拳

只适用于分析Input dispatching的anr类型,广播和service本身就没有焦点和界面。

Log1、高cpu
从anr时间点往前倒退,搜索进程号、包名。筛选am、wm、input_focus、finishDrawing等关键log信息,查看时间点大概可以知道卡在哪里。

//monkey启动界面
S5E3560  04-21 18:42:09.325 32440  1961 I ActivityTaskManager: START u0 {act=android.intent.action.MAIN cat=[android.intent.category.LAUNCHER] flg=0x4000000 cmp=com.google.android.youtube/com.google.android.apps.youtube.app.watchwhile.WatchWhileActivity (has extras)} from uid 10139, pid 29486
M5E3561  04-21 18:42:09.327 14991 15005 I Monkey  :     // Allowing start of Intent { act=android.intent.action.MAIN cat=[android.intent.category.LAUNCHER] cmp=com.google.android.youtube/com.google.android.apps.youtube.app.watchwhile.WatchWhileActivity} in package com.google.android.youtube
//wm_set_resumed_activity
E5E3690  04-21 18:42:10.078 32440 32471 I wm_set_resumed_activity: [0,com.google.android.youtube/com.google.android.apps.youtube.app.watchwhile.WatchWhileActivity,minimalResumeActivityLocked]
//anr倒计时开始
M5E3692  04-21 18:42:10.081 32440 32619 W InputDispatcher: Waiting because no window has focus but ActivityRecord{b74ee7e u0 com.google.android.youtube/com.google.android.apps.youtube.app.watchwhile.WatchWhileActivity} t2581 d0} may eventually add a window when it finishes starting up. Will wait for 5000ms
//wm_on_resume_called
E5E3B2E  04-21 18:42:12.906 29486 29486 I wm_on_resume_called: [192212606,com.google.android.apps.youtube.app.watchwhile.WatchWhileActivity,RESUME_ACTIVITY]
//请求焦点
E5E3BD1  04-21 18:42:13.653 32440 32472 I input_focus: [Focus request 2f78879 com.google.android.youtube/com.google.android.apps.youtube.app.watchwhile.WatchWhileActivity,reason=UpdateInputWindows]
//anr触发
S5E3DF6  04-21 18:42:15.208 32440 32619 I WindowManager: ANR in ActivityRecord{b74ee7e u0 com.google.android.youtube/com.google.android.apps.youtube.app.watchwhile.WatchWhileActivity} t2581 d0}.  Reason: Application does not have a focused window
//dump window
S5E3E4B  04-21 18:42:15.538 32440 32619 I WindowManager: Dump Win No.11 win= Window{2f78879 u0 com.google.android.youtube/com.google.android.apps.youtube.app.watchwhile.WatchWhileActivity}-[Surface(name=*Title#64219)/@0xbd4f68e], flags=0x81810100, canReceive=true, canReceiveKeysReason: fromTouch= false isVisibleRequestedOrAdding=true mViewVisibility=0 mRemoveOnExit=false flags=-2122252032 appWindowsAreFocusable=true canReceiveTouchInput=true displayIsOnTop=true displayIsTrusted=true, ViewVisibility=0, mWinAnimator=WindowStateAnimator{90d4cdf com.google.android.youtube/com.google.android.apps.youtube.app.watchwhile.WatchWhileActivity}
S5E3E4C  04-21 18:42:15.539 32440 32619 I WindowManager:  win.mActivityRecord=ActivityRecord{b74ee7e u0 com.google.android.youtube/com.google.android.apps.youtube.app.watchwhile.WatchWhileActivity} t2581 d0}, isSurfaceShowing()=true, isFreezingScreen()=false, isDestroyable()=false, isClientVisible(()=true, isSleeping(()=false, isInHistory()=true, isFocusable()=true
S5E3E4D  04-21 18:42:15.539 32440 32619 I WindowManager: , DrawState=1, mSurfaceController=Surface(name=com.google.android.youtube/com.google.android.apps.youtube.app.watchwhile.WatchWhileActivity#64219)/@0xbd4f68e
S5E3E4E  04-21 18:42:15.539 32440 32619 I WindowManager: , mSurfaceController.getShown()=false
S5E3E4F  04-21 18:42:15.539 32440 32619 I WindowManager: , relayoutCalled=true, viewVis=0, attachHid=false, exiting=false, destroying=false hiddenRequested=true
//finishDrawing
S5E3E7D  04-21 18:42:15.583 32440  2560 D WindowManager: finishDrawing: syncSeqId=0, postDrawTransaction=android.view.SurfaceControl$Transaction@d16b5eb, mSyncState=0, mDrawState=1, hasSyncHandlers=false, mClientWasDrawingForSync=false, win=Window{2f78879 u0 com.google.android.youtube/com.google.android.apps.youtube.app.watchwhile.WatchWhileActivity}-[Surface(name=*Title#64219)/@0xbd4f68e]
//获得焦点
E5E3EDA  04-21 18:42:15.756 32440 32619 I input_focus: [Focus entering 2f78879 com.google.android.youtube/com.google.android.apps.youtube.app.watchwhile.WatchWhileActivity (server),reason=Window became focusable. Previous reason: NOT_VISIBLE]
//am_anr
E5E3F67  04-21 18:42:15.984 32440 31031 I am_anr  : [0,29486,com.google.android.youtube,819707589,Input dispatching timed out (Application does not have a focused window)]
//anr log
S5E42AC  04-21 18:42:17.471 32440 31031 E ActivityManager: ANR in com.google.android.youtube (com.google.android.youtube/com.google.android.apps.youtube.app.watchwhile.WatchWhileActivity)
S5E42AC  04-21 18:42:17.471 32440 31031 E ActivityManager: PID: 29486
S5E42AC  04-21 18:42:17.471 32440 31031 E ActivityManager: Reason: Input dispatching timed out (Application does not have a focused window)
S5E42AC  04-21 18:42:17.471 32440 31031 E ActivityManager: Parent: com.google.android.youtube/com.google.android.apps.youtube.app.watchwhile.WatchWhileActivity
S5E42AC  04-21 18:42:17.471 32440 31031 E ActivityManager: ErrorId: 811aa17a-4602-464e-b9cc-fcfc861fb5e1
S5E42AC  04-21 18:42:17.471 32440 31031 E ActivityManager: Frozen: false
S5E42AC  04-21 18:42:17.471 32440 31031 E ActivityManager: Load: 0.0 / 0.0 / 0.0
S5E42AC  04-21 18:42:17.471 32440 31031 E ActivityManager: ----- Output from /proc/pressure/memory -----
S5E42AC  04-21 18:42:17.471 32440 31031 E ActivityManager: some avg10=39.56 avg60=27.98 avg300=21.68 total=1551356201
S5E42AC  04-21 18:42:17.471 32440 31031 E ActivityManager: full avg10=7.24 avg60=6.79 avg300=6.69 total=658443539
S5E42AC  04-21 18:42:17.471 32440 31031 E ActivityManager: ----- End output from /proc/pressure/memory -----
S5E42AC  04-21 18:42:17.471 32440 31031 E ActivityManager: 
S5E42AC  04-21 18:42:17.471 32440 31031 E ActivityManager: CPU usage from 5257ms to 0ms ago (2023-04-21 18:42:10.527 to 2023-04-21 18:42:15.784):
S5E42AC  04-21 18:42:17.471 32440 31031 E ActivityManager:   108% 29486/com.google.android.youtube: 89% user + 19% kernel / faults: 37141 minor 386 major
S5E42AC  04-21 18:42:17.471 32440 31031 E ActivityManager:   70% 143/kswapd0: 0% user + 70% kernel
...
S5E42AE  04-21 18:42:17.471 32440 31031 E ActivityManager: 99% TOTAL: 49% user + 45% kernel + 0.5% iowait + 2.4% irq + 1.3% softirq

18:42:10.078	wm_set_resumed_activity
18:42:10.081	InputDispatcher
18:42:12.906	wm_on_resume_called
18:42:13.653	input_focus: [Focus request
18:42:15.208	WindowManager: ANR
18:42:15.583	finishDrawing
18:42:15.756	input_focus: [Focus entering

//展锐平台的ylog下面有sgm.csv文件,可以看到cpu的使用率,从anr时间点往前十秒左右,作为参考数据
//sgm cpu信息
4-28 7:53:23.217<34493.380164>    99    5
4-28 7:53:24.220<34494.383040>    100    0
4-28 7:53:25.225<34495.387814>    100    0
4-28 7:53:26.228<34496.391343>    100    0
4-28 7:53:27.231<34497.394239>    100    0
4-28 7:53:28.235<34498.397655>    98    29
4-28 7:53:29.237<34499.399598>    91    48
4-28 7:53:30.240<34500.402403>    89    43
4-28 7:53:31.249<34501.411557>    95    9

Log2、高iowait

//应用启动
M4882DF  04-21 21:43:19.883   617   617 D Zygote  : Forked child process 19996
//启动界面
S4883E2  04-21 21:43:20.713  1161  1303 I ActivityTaskManager: ->startActivity for ActivityRecord{6f24aaa u0 com.quora.android/.components.activities.FullScreenActivity} t16454 d0} result:START_SUCCESS
M4883E3  04-21 21:43:20.716 19924 19938 I Monkey  :     // activityResuming(com.quora.android)
//setFocusedApp、wm_set_resumed_activity
S4883F1  04-21 21:43:20.790  1161  1303 D WindowManager: setFocusedApp mFocusedApp = ActivityRecord{6f24aaa u0 com.quora.android/.components.activities.FullScreenActivity} t16454 d0}displayId = 0Callers = com.android.server.wm.ActivityTaskManagerService.setResumedActivityUncheckLocked:4576 com.android.server.wm.TaskFragment.onActivityStateChanged:826 com.android.server.wm.ActivityRecord.setState:5504 com.android.server.wm.Task.minimalResumeActivityLocked:4804 
E4883F2  04-21 21:43:20.790  1161  1303 I wm_set_resumed_activity: [0,com.quora.android/.components.activities.FullScreenActivity,minimalResumeActivityLocked]

//界面start
E4883E5  04-21 21:43:20.716 19996 19996 I wm_on_start_called: [247999256,com.quora.android.components.activities.LauncherActivity,handleStartActivity]
//应用内部图形 Graph API调用出错
M4883E6  04-21 21:43:20.784 19996 20051 W GraphRequest: Starting with v13 of the SDK, a client token must be embedded in your client code before making Graph API calls. Visit https://developers.facebook.com/docs/android/getting-started#client-token to learn how to implement this change.
//monkey发送事件
M488400  04-21 21:43:20.872 19924 19924 I Monkey  : :Sending Trackball (ACTION_MOVE): 0:(2.0,-2.0)
//FullScreenActivity no window,开始anr五秒倒计时
M488401  04-21 21:43:20.872  1161  1342 W InputDispatcher: Waiting because no window has focus but ActivityRecord{6f24aaa u0 com.quora.android/.components.activities.FullScreenActivity} t16454 d0} may eventually add a window when it finishes starting up. Will wait for 5000ms


//apk 内的性能检测器log显示 onResume耗时 4681626微秒,也就是4681ms
M488782  04-21 21:43:24.788 19996 19996 D FirebasePerformance: onResume(): com.quora.android.components.activities.FullScreenActivity: 4681626 microseconds
//界面Resume
E48878C  04-21 21:43:24.801 19996 19996 I wm_on_resume_called: [116542122,com.quora.android.components.activities.FullScreenActivity,RESUME_ACTIVITY]
//请求焦点
E4887CC  04-21 21:43:25.005  1161  1202 I input_focus: [Focus request 212cae8 com.quora.android/com.quora.android.components.activities.FullScreenActivity,reason=UpdateInputWindows]

//五秒到了,触发anr
S488881  04-21 21:43:25.876  1161  1342 I WindowManager: ANR in ActivityRecord{6f24aaa u0 com.quora.android/.components.activities.FullScreenActivity} t16454 d0}.  Reason: Application does not have a focused window

//dump window
S4888DA  04-21 21:43:25.987  1161  1342 I WindowManager: Dump Win No.9 win= Window{212cae8 u0 com.quora.android/com.quora.android.components.activities.FullScreenActivity}-[Surface(name=*Title#86212)/@0x3c73830], flags=0x81810100, canReceive=true, canReceiveKeysReason: fromTouch= false isVisibleRequestedOrAdding=true mViewVisibility=0 mRemoveOnExit=false flags=-2122252032 appWindowsAreFocusable=true canReceiveTouchInput=true displayIsOnTop=true displayIsTrusted=true, ViewVisibility=0, mWinAnimator=WindowStateAnimator{bd98cee com.quora.android/com.quora.android.components.activities.FullScreenActivity}
S4888DB  04-21 21:43:25.987  1161  1342 I WindowManager:  win.mActivityRecord=ActivityRecord{6f24aaa u0 com.quora.android/.components.activities.FullScreenActivity} t16454 d0}, isSurfaceShowing()=true, isFreezingScreen()=false, isDestroyable()=false, isClientVisible(()=true, isSleeping(()=false, isInHistory()=true, isFocusable()=true
S4888DC  04-21 21:43:25.987  1161  1342 I WindowManager: , DrawState=1, mSurfaceController=Surface(name=com.quora.android/com.quora.android.components.activities.FullScreenActivity#86212)/@0x3c73830
S4888DD  04-21 21:43:25.987  1161  1342 I WindowManager: , mSurfaceController.getShown()=false
S4888DE  04-21 21:43:25.987  1161  1342 I WindowManager: , relayoutCalled=true, viewVis=0, attachHid=false, exiting=false, destroying=false hiddenRequested=true

//am_anr
E48893F  04-21 21:43:26.071  1161 20316 I am_anr  : [0,19996,com.quora.android,952680004,Input dispatching timed out (Application does not have a focused window)]

//finishDrawing
S488959  04-21 21:43:26.104  1161  1785 I WindowManager: finishDrawing of orientation change: Window{212cae8 u0 com.quora.android/com.quora.android.components.activities.FullScreenActivity}-[Surface(name=*Title#86212)/@0x3c73830] 918ms

//anr log
S488C9E  04-21 21:43:27.908  1161 20316 E ActivityManager: ANR in com.quora.android (com.quora.android/.components.activities.FullScreenActivity)
S488C9E  04-21 21:43:27.908  1161 20316 E ActivityManager: PID: 19996
S488C9E  04-21 21:43:27.908  1161 20316 E ActivityManager: Reason: Input dispatching timed out (Application does not have a focused window)
S488C9E  04-21 21:43:27.908  1161 20316 E ActivityManager: Parent: com.quora.android/.components.activities.FullScreenActivity
S488C9E  04-21 21:43:27.908  1161 20316 E ActivityManager: ErrorId: 82fd6234-0450-4b87-a8c2-680010045f46
S488C9E  04-21 21:43:27.908  1161 20316 E ActivityManager: Frozen: false
S488C9E  04-21 21:43:27.908  1161 20316 E ActivityManager: Load: 0.0 / 0.0 / 0.0
S488C9E  04-21 21:43:27.908  1161 20316 E ActivityManager: ----- Output from /proc/pressure/memory -----
S488C9E  04-21 21:43:27.908  1161 20316 E ActivityManager: some avg10=12.29 avg60=7.50 avg300=5.71 total=734264998
S488C9E  04-21 21:43:27.908  1161 20316 E ActivityManager: full avg10=8.62 avg60=4.83 avg300=3.51 total=430997276
S488C9E  04-21 21:43:27.908  1161 20316 E ActivityManager: ----- End output from /proc/pressure/memory -----
S488C9E  04-21 21:43:27.908  1161 20316 E ActivityManager: 
S488C9E  04-21 21:43:27.908  1161 20316 E ActivityManager: CPU usage from 8246ms to 0ms ago (2023-04-21 21:43:17.792 to 2023-04-21 21:43:26.038):
S488C9E  04-21 21:43:27.908  1161 20316 E ActivityManager:   49% 143/kswapd0: 0% user + 49% kernel
S488C9E  04-21 21:43:27.908  1161 20316 E ActivityManager:   42% 1161/system_server: 22% user + 19% kernel / faults: 18241 minor 1714 major
...
//iowait高
S488CA0  04-21 21:43:27.908  1161 20316 E ActivityManager: 74% TOTAL: 19% user + 22% kernel + 29% iowait + 1.2% irq + 1% softirq

//monkey下发事件期间,iowait占用率从21:43:21----21:43:27一直比较高
4-21 21:43:21.030<19791.857506>	80	41
4-21 21:43:22.032<19792.860107>	84	49
4-21 21:43:23.035<19793.862844>	75	36
4-21 21:43:24.038<19794.865520>	78	45
4-21 21:43:25.040<19795.868259>	60	23
4-21 21:43:26.043<19796.871034>	79	39
4-21 21:43:27.050<19797.877821>	94	27

21:43:20.790	wm_set_resumed_activity
21:43:20.872	InputDispatcher 
21:43:24.801	wm_on_resume_called
21:43:25.005	input_focus
21:43:25.876	WindowManager: ANR
21:43:26.104	WindowManager: finishDrawing

3、关键字
anr相关:ANR in 、am_anr、WindowManager: ANR in ActivityRecord
wm生命周期:wm_set_resumed_activity、wm_on_resume_called、Zygote : Forked child process、WindowManager: finishDrawing、am_kill : [0,23853,wp.wattpad,0,bg anr]、
输入事件下发:InputDispatcher
焦点:input_focus
耗时相关:CheckTime、Choreographer、OpenGLRenderer、
低内存杀进程:lowmemorykiller、killinfo


CheckTime

//CheckTime
M135EDC  04-28 10:58:37.421  3537  3537 W CheckTime: App running slow: Executing application classloader create took 2796ms
M1360FF  04-28 10:58:39.490  3537  3537 W CheckTime: App running slow: Executing handleBindApplication : makeApplication took 1129ms
M13641B  04-28 10:58:43.993  3537  3537 W CheckTime: App running slow: Executing ContentProviderInfo{name=com.ubercab.androidx-startup className=androidx.startup.InitializationProvider} onCreate took 2777ms
M1364A5  04-28 10:58:44.687  3537  3537 W CheckTime: App running slow: Executing handleBindApplication : installContentProviders took 5198ms

Choreographer、OpenGLRenderer

//主线程跳帧
M1380D2  04-28 10:59:12.484  3537  3537 I Choreographer: Skipped 1849 frames!  The application may be doing too much work on its main thread.
//主线程卡顿
MA423E8  05-01 18:34:41.901  6631  7139 I OpenGLRenderer: Davey! duration=2105ms;
MA423ED  05-01 18:34:41.911  6631  6631 I Choreographer: Skipped 123 frames!  The application may be doing too much work on its main thread.

lowmemorykiller、killinfo

//lowmemorykiller
MAB564D  04-30 23:21:31.339   329   329 I lowmemorykiller: Kill 'com.tophatch.concepts' (30744), uid 10240, oom_score_adj 900 to free 238396kB rss, 28932kB swap; reason: low watermark is breached and swap is low (200060kB < 238376kB)
EAB564E  04-30 23:21:31.339   329   329 I killinfo: [30744,10240,900,201,238396,3,22564,1112320,36832,1316,28972,116608,2383768,200060,440136,440676,458900,509192,845744,112316,337812,57984,90912,0,0,2572,128,372,12,31,0,28932,326536,4,4,37.750000,9.480000,12.840000,1.340000,69.589996]

GC

//gc log
M8959B8  05-03 01:26:35.147  1760  1768 I droid.launcher3: Background young concurrent copying GC freed 4(88B) AllocSpace objects, 0(0B) LOS objects, 0% free, 255MB/256MB, paused 61us,33us total 416.133ms
M8959E8  05-03 01:26:36.274  1760  1760 I droid.launcher3: Alloc concurrent copying GC freed 21(776B) AllocSpace objects, 0(0B) LOS objects, 0% free, 255MB/256MB, paused 86us,35us total 1.127s
M895A02  05-03 01:26:37.635  1760  1760 I droid.launcher3: Alloc concurrent copying GC freed 627687(23MB) AllocSpace objects, 0(0B) LOS objects, 9% free, 232MB/256MB, paused 58us,40us total 1.360s

Reason: executing service

//Zygote
M135CCB  04-28 10:58:34.438   906   906 D Zygote  : Forked child process 3537
E135CCC  04-28 10:58:34.438  1450  1495 I am_proc_start: [0,3537,10273,com.ubercab,service,{com.ubercab/com.google.android.datatransport.runtime.scheduling.jobscheduling.JobInfoSchedulerService}]
S135CCE  04-28 10:58:34.439  1450  1495 I ActivityManager: Start proc 3537:com.ubercab/u0a273 for service {com.ubercab/com.google.android.datatransport.runtime.scheduling.jobscheduling.JobInfoSchedulerService}
//am_create_service
E135CE7  04-28 10:58:34.551  1450  2800 I am_create_service: [0,210793165,.JobInfoSchedulerService,10273,3537]
//CheckTime
M135EDC  04-28 10:58:37.421  3537  3537 W CheckTime: App running slow: Executing application classloader create took 2796ms
M1360FF  04-28 10:58:39.490  3537  3537 W CheckTime: App running slow: Executing handleBindApplication : makeApplication took 1129ms
M13641B  04-28 10:58:43.993  3537  3537 W CheckTime: App running slow: Executing ContentProviderInfo{name=com.ubercab.androidx-startup className=androidx.startup.InitializationProvider} onCreate took 2777ms
M1364A5  04-28 10:58:44.687  3537  3537 W CheckTime: App running slow: Executing handleBindApplication : installContentProviders took 5198ms

//bind service time out
S136C7C  04-28 10:58:52.425  1450  1450 W JobServiceContext: Time-out while trying to bind ef0be1 #u0a273/33369675 com.ubercab/com.google.android.datatransport.runtime.scheduling.jobscheduling.JobInfoSchedulerService, dropping.

//callApplicationOnCreate took 27535ms
M1380A3  04-28 10:59:12.223  3537  3537 W CheckTime: App running slow: Executing handleBindApplication : callApplicationOnCreate took 27535ms
//Timeout executing service
S1380D0  04-28 10:59:12.445  1450  1494 W ActivityManager: Timeout executing service: ServiceRecord{c9072cd u0 com.ubercab/com.google.android.datatransport.runtime.scheduling.jobscheduling.JobInfoSchedulerService}
//主线程跳帧
M1380D2  04-28 10:59:12.484  3537  3537 I Choreographer: Skipped 1849 frames!  The application may be doing too much work on its main thread.
//am_anr
E138138  04-28 10:59:12.708  1450  7464 I am_anr  : [0,3537,com.ubercab,551042628,executing service com.ubercab/com.google.android.datatransport.runtime.scheduling.jobscheduling.JobInfoSchedulerService]
//anr log
S139588  04-28 10:59:23.279  1450  7464 E ActivityManager: ANR in com.ubercab
S139588  04-28 10:59:23.279  1450  7464 E ActivityManager: PID: 3537
S139588  04-28 10:59:23.279  1450  7464 E ActivityManager: Reason: executing service com.ubercab/com.google.android.datatransport.runtime.scheduling.jobscheduling.JobInfoSchedulerService
S139588  04-28 10:59:23.279  1450  7464 E ActivityManager: ErrorId: 53e852d6-a617-427b-ab69-4e8220e2c1c0
S139588  04-28 10:59:23.279  1450  7464 E ActivityManager: Frozen: false
S139588  04-28 10:59:23.279  1450  7464 E ActivityManager: Load: 0.0 / 0.0 / 0.0
S139588  04-28 10:59:23.279  1450  7464 E ActivityManager: ----- Output from /proc/pressure/memory -----
S139588  04-28 10:59:23.279  1450  7464 E ActivityManager: some avg10=26.45 avg60=22.21 avg300=17.78 total=5862518578
S139588  04-28 10:59:23.279  1450  7464 E ActivityManager: full avg10=13.65 avg60=11.39 avg300=8.40 total=3073502314
S139588  04-28 10:59:23.279  1450  7464 E ActivityManager: ----- End output from /proc/pressure/memory -----
S139588  04-28 10:59:23.279  1450  7464 E ActivityManager: 
S139588  04-28 10:59:23.279  1450  7464 E ActivityManager: CPU usage from 0ms to 10663ms later (2023-04-28 10:59:12.558 to 2023-04-28 10:59:23.221):
S139588  04-28 10:59:23.279  1450  7464 E ActivityManager:   40% 1450/system_server: 23% user + 17% kernel / faults: 13035 minor 6701 major
S139588  04-28 10:59:23.279  1450  7464 E ActivityManager:   33% 7249/com.facebook.katana: 24% user + 8.9% kernel / faults: 37769 minor 747 major
S139588  04-28 10:59:23.279  1450  7464 E ActivityManager:   33% 143/kswapd0: 0% user + 33% kernel
...
S13958A  04-28 10:59:23.279  1450  7464 E ActivityManager: 86% TOTAL: 27% user + 22% kernel + 33% iowait + 1.3% irq + 1.1% softirq
S13958A  04-28 10:59:23.279  1450  7464 E ActivityManager: CPU usage from 45642720ms to 45642720ms ago (1970-01-01 08:00:00.000 to 1970-01-01 08:00:00.000) with 0% awake:
S13958A  04-28 10:59:23.279  1450  7464 E ActivityManager: 0% TOTAL: 0% user + 0% kernel

Reason: Broadcast of Intent

//Add broadcast
S0BE79A  04-27 22:56:53.962  1450  1630 D BroadcastQueue: Add broadcast <BroadcastRecord{a7715d9 u0 com.google.firebase.INSTANCE_ID_EVENT}> into [ordered | background], pending size 0
S0BE79A  04-27 22:56:53.962  1450  1630 D BroadcastQueue: Header is BroadcastRecord{a7715d9 u0 com.google.firebase.INSTANCE_ID_EVENT} now

S0BE7A4  04-27 22:56:53.970  1450  1630 D AlarmManager: sending alarm.type = 3, action = com.google.firebase.INSTANCE_ID_EVENT, alarm = Alarm{c36f64c type 3 origWhen 2293731 whenElapsed 2293731 com.amulyam}, cn = ComponentInfo{com.amulyam/com.google.firebase.iid.FirebaseInstanceIdInternalReceiver}, operation = PendingIntent{e31306: PendingIntentRecord{63f1268 com.amulyam broadcastIntent}}, listener=null, listenerTag=null, workSource=null

//启动应用
M0BE7AE  04-27 22:56:53.986   906   906 D Zygote  : Forked child process 13409
E0BE7AF  04-27 22:56:53.987  1450  1495 I am_proc_start: [0,13409,10212,com.amulyam,broadcast,{com.amulyam/com.google.firebase.iid.FirebaseInstanceIdInternalReceiver}]
S0BE7B0  04-27 22:56:53.987  1450  1495 E UnisocWatchdog: WDT_Monitor_wpp processJavaStarted 3rd:com.amulyam,pid=13409
S0BE7B1  04-27 22:56:53.987  1450  1495 I ActivityManager: Start proc 13409:com.amulyam/u0a212 for broadcast {com.amulyam/com.google.firebase.iid.FirebaseInstanceIdInternalReceiver}

//应用内部打印No response
M0C064A  04-27 22:57:24.265 13409 13448 W InstanceID/Rpc: No response
M0C064B  04-27 22:57:24.274 13409 13448 D FirebaseInstanceId: background sync failed: TIMEOUT, retry in 30s

//广播60秒超时
S0C1D22  04-27 22:57:53.984  1450  1494 W BroadcastQueue: Timeout of broadcast BroadcastRecord{a7715d9 u0 com.google.firebase.INSTANCE_ID_EVENT} - receiver=android.os.BinderProxy@4bcf518, started 60001ms ago
S0C1D23  04-27 22:57:53.984  1450  1494 W BroadcastQueue: Receiver during timeout of BroadcastRecord{a7715d9 u0 com.google.firebase.INSTANCE_ID_EVENT} : ResolveInfo{fb1db71 com.amulyam/com.google.firebase.iid.FirebaseInstanceIdInternalReceiver m=0x0}
E0C1D24  04-27 22:57:53.984  1450  1494 I am_broadcast_discard_app: [0,175576537,com.google.firebase.INSTANCE_ID_EVENT,0,ResolveInfo{fb1db71 com.amulyam/com.google.firebase.iid.FirebaseInstanceIdInternalReceiver m=0x0}]
S0C1D25  04-27 22:57:53.991  1450  1494 D BroadcastQueue: Finished with ordered broadcast BroadcastRecord{a7715d9 u0 com.google.firebase.INSTANCE_ID_EVENT} receivers:([ResolveInfo{fb1db71 com.amulyam/com.google.firebase.iid.FirebaseInstanceIdInternalReceiver m=0x0}]) take 60030ms in [background], remains 19

//am_anr
E0C1D33  04-27 22:57:54.033  1450 19684 I am_anr  : [0,13409,com.amulyam,948485700,Broadcast of Intent { act=com.google.firebase.INSTANCE_ID_EVENT flg=0x14 cmp=com.amulyam/com.google.firebase.iid.FirebaseInstanceIdInternalReceiver (has extras) }]

//anr
M0C1D7B  04-27 22:57:54.284 13409 13417 I com.amulyam: Wrote stack traces to tombstoned
S0C1D7C  04-27 22:57:54.286  1450 19684 I ActivityManager: Done dumping
S0C1D7D  04-27 22:57:54.288  1450 19684 E ActivityManager: ANR in com.amulyam
S0C1D7D  04-27 22:57:54.288  1450 19684 E ActivityManager: PID: 13409
S0C1D7D  04-27 22:57:54.288  1450 19684 E ActivityManager: Reason: Broadcast of Intent { act=com.google.firebase.INSTANCE_ID_EVENT flg=0x14 cmp=com.amulyam/com.google.firebase.iid.FirebaseInstanceIdInternalReceiver (has extras) }
S0C1D7D  04-27 22:57:54.288  1450 19684 E ActivityManager: ErrorId: 3e6ebf3d-f35e-41f9-950d-13d2f2e73c3d
S0C1D7D  04-27 22:57:54.288  1450 19684 E ActivityManager: Frozen: false
S0C1D7D  04-27 22:57:54.288  1450 19684 E ActivityManager: Load: 0.0 / 0.0 / 0.0
S0C1D7D  04-27 22:57:54.288  1450 19684 E ActivityManager: ----- Output from /proc/pressure/memory -----
S0C1D7D  04-27 22:57:54.288  1450 19684 E ActivityManager: some avg10=8.08 avg60=8.20 avg300=9.05 total=277086647
S0C1D7D  04-27 22:57:54.288  1450 19684 E ActivityManager: full avg10=4.65 avg60=4.77 avg300=5.22 total=146245129
S0C1D7D  04-27 22:57:54.288  1450 19684 E ActivityManager: ----- End output from /proc/pressure/memory -----

结尾

除了一些简单的anr,比如死锁、耗时方法等针对应用内部的分析方法。
google的或者三方的一些应用,只能通过系统log推断anr的原因。

目前还是个新手,刚开始学习anr初步分析和归类。哈哈哈哈哈~

本文标签: androidANR