Understanding ANR's past and present, solving ANR is so simple!

1. What is ANR?

ANR (application not responding) means that the application has no response.

2. What is the cause of ANR?

The root cause of ANR is that the app blocks the UI thread. In the Android system, each app has only one UI thread, which is generated by default when the app is created. The UI thread initializes a message loop by default to process UI messages, ANR often times out when processing UI messages. What are the sources of the UI message? There are two main sources:

2.1 callback message from AMS

In the Android system, an application consists of four components of Android. AMS is responsible for managing the lifecycle of the four components of the application, when AMS calls back the life cycle of an Application Component beyond the response time defined by AMS, AMS reports ANR. This is generally because time-consuming operations (such as network operations, SD card file operations, database operations, and massive computing) are performed in the callback functions of these components ), the common callback functions and timeout time of AMS for components are as follows:

• Activity: oncreate (), onresume (), ondestroy (), onkeydown (), onclick (), timeout of 5 S
• Service: oncreate (), onstart (), ondestroy () and so on, timeout time 20 s
• Broadcastreceiver: onreceiver (). The broadcast timeout time of the foreground app is 10 s, and that of the background app is 60 s.

2.2 messages sent by the app

In addition to the callback messages of AMS to the four components running in the UI thread, some operations are also running in the UI thread:

• Asynctask: onpreexecute (), onprogressupdate (), onpostexecute (), oncancel (), etc., timeout 5 S
• Mainthread handler: handlemessage (), post * (runnable R), etc., timeout 5 S

3. How to Avoid ANR?

Knowing the cause of ANR, it is easy to avoid it, that is, do not perform time-consuming operations in the above two cases. Common time-consuming operations include network operations, SD card file operations, database operations, and massive computing. It is easy to say, but sometimes it will be forgotten, so Android provided us with the strictmode class (Android. OS. strictmode), strictmode provides two main functions: one is to monitor the time-consuming operations of the UI thread (disk read/write, network access, custom code with slow running speed ), second, monitor memory leakage (such as activity, SQLite, I/O streams, and large objects not released ). If we violate its monitoring policy during the development process, strictmode will output a warning message in logcat.

How to enable strictmode in the app? Generally, the following two rows are added to the oncreate function of mainactiviyt:

Strictmode. setthreadpolicy (New strictmode. threadpolicy. Builder (). detectall (). penaltylog (). penaltydialog (). Build (); // enable UI thread monitoring
Strictmode. setvmpolicy (New strictmode. vmpolicy. Builder (). detectall (). penaltylog (). Build (); // enable VM memory monitoring

Of course, strictmode is suitable for the test version and should be blocked for the official release to avoid affecting app performance. The following is an example of warning output for writing a database violation policy in the UI thread after strictmode is Enabled:

09-04 16:15:34. 592: Debug/strictmode (15883): strictmode policy violation ;~ Duration= 319 MS: Android. OS. strictmode $ strictmodediskwriteviolation: Policy = 31 violation = 1
09-04 16:15:34. 592: Debug/strictmode (15883): at Android. OS. strictmode $ androidblockguardpolicy. onwritetodisk (strictmode. Java: 1041)
09-04 16:15:34. 592: Debug/strictmode (15883): at Android. database. SQLite. sqlitestatement. acquireandlock (sqlitestatement. Java: 219)
09-04 16:15:34. 592: Debug/strictmode (15883): At android.database.sqlite.sqlitestatement.exe cuteupdatedelete (sqlitestatement. Java: 83)
09-04 16:15:34. 592: Debug/strictmode (15883): at Android. database. SQLite. sqlitedatabase. updatewithonconflict (sqlitedatabase. Java: 1829)
09-04 16:15:34. 592: Debug/strictmode (15883): at Android. database. SQLite. sqlitedatabase. Update (sqlitedatabase. Java: 1780)
09-04 16:15:34. 592: Debug/strictmode (15883): At com. Test. Tutorial. Data. listprovider. Update (tutlistprovider. Java: 188)
09-04 16:15:34. 592: Debug/strictmode (15883): at Android. content. contentprovider $ transport. Update (contentprovider. Java: 233)
...

Time required for calling stacks and UI threads.

4. How to analyze the ANR?

Although we have taken prevention measures, sometimes some people still do not pay attention to the cause of ANR. So how can we quickly locate the problem when ANR occurs? Remember that when ANR occurs, Android will give an important message in two places: logcat and \ data \ ANR \ traces.txt. Of course, bugreport has the most comprehensive information, both of which are available.

4.1 logcat Information

In the case of ANR, logcat will output the ANR occurrence time and the CPU usage before and after ANR, for example, the next ANR logcat output information example:

04-01 13:12:11. 572I/inputdispatcher (220): application is not responding: Window {2b263310com. Android. Email/COM. Android. Email. activity. splitscreenactivitypaused = false}. 5009.8 Ms since event, 5009.5 Ms since waitstarted
04-011. 572 I/windowmanager (220): input event dispatching timedout sending tocom. Android. Email/COM. Android. Email. activity. splitscreenactivity
04-0113:12:14. 123 I/process (220): Sending signal. PID: 21404 Sig: 3 ---OccurredANRTime and generationTrace.txtTime
......
04-011. 872 E/activitymanager (220): ANR in COM. Android. Email (COM. Android. Email/. activity. splitscreenactivity)
04-011. 872 E/activitymanager (220): reason: keydispatchingtimedout
04-011. 872 E/activitymanager (220): load: 8.68/8.37/8.53
04-011. 872 E/activitymanager (220 ):Cpuusage from 4361 ms to 699 Ms ago----CPU usage before ANR
04-011. 872 E/activitymanager (220): 5.5% 21404/COM. Android. Email: 1.3% user + 4.1% kernel/faults: 10 minor
04-011. 872 E/activitymanager (220): 4.3% 220/system_server: 2.7% user + 1.5% kernel/faults: 11 minor 2 major
04-011. 872 E/activitymanager (220): 0.9% 52/spi_qsd.0: 0% user + 0.9% Kernel
04-011. 872 E/activitymanager (220): 0.5% 65/IRQ/170-cyttsp-: 0% user + 0.5% Kernel
04-011. 872 E/activitymanager (220): 0.5% 296/COM. Android. systemui: 0.5% user + 0% Kernel
04-011. 872 E/activitymanager (220 ):100% total: 4.8% user + 7.6% kernel + 87% iowait
04-011. 872 E/activitymanager (220 ):Cpuusage from 3697 ms to 4223 ms later:--CPU usage after ANR
04-011. 872 E/activitymanager (220): 25% 21404/COM. Android. Email: 25% user + 0% kernel/faults: 191 minor
04-011. 872 E/activitymanager (220): 16% 21603/_ EAS (par. Hakan: 16% user + 0% Kernel
04-011. 872 E/activitymanager (220): 7.2% 21406/GC: 7.2% user + 0% Kernel
04-011. 872 E/activitymanager (220): 1.8% 21409/Compiler: 1.8% user + 0% Kernel
04-011. 872 E/activitymanager (220): 5.5% 220/system_server: 0% user + 5.5% kernel/faults: 1 minor
04-011. 872 E/activitymanager (220): 5.5% 263/inputdispatcher: 0% user + 5.5% Kernel
04-011. 872 E/activitymanager (220 ):32% Total: 28% user + 3.7% Kernel

The log shows the ANR type and CPU usage:

• If the CPU usage is close to 100%, it indicates that the current device is busy, possibly because of CPU hunger
• If the CPU usage is small, the main thread is blocked.
• If iowait is high, it may be caused by the I/O operation of the main thread.

4.2 traces Information

When ANR occurs, Android also records ANR information to the/data/ANR/traces.txt file, which can be opened in multiple ways. Example of the hosts file:

----- PID 2140413:12:14-----ANR occurrence time
Using line: COM. Android. EmailAPP package name in which ANR occurs
Dalvik threads:Virtual Machine thread Information
(Mutexes: tll = 0tsl = 0 tscl = 0 ghl = 0 hwl = 0 hwll = 0)
"Main" PRIO = 5 tid = 1Native main thread status: JNI call is executed
| Group = "Main" scount = 1 dscount = 0obj = 0x2aad2248 self = 0xcf70
| Shard id = 21404 nice = 0 sched = 0/0 RGPS = [fopen-error: 2] handle = 1876218976
At Android. OS. messagequeue. nativepollonce (NATIVE METHOD) Call Stack
At Android. OS. messagequeue. Next (messagequeue. Java: 119)
At Android. OS. lorule. Loop (lorule. Java: 110)
At Android. App. activitythread. Main (activitythread. Java: 3688)
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: 866)
At com. Android. Internal. OS. zygoteinit. Main (zygoteinit. Java: 624)
At Dalvik. system. nativestart. Main (native method)
... Other threads

ThreadStatus description:
Threadstate (defined at "Dalvik/Vm/thread. H")
Thread_undefined =-1,/* Makes Enum compatible with int32_t */
Thread_zombie = 0,/* terminated */
Thread_running = 1,/* runnable or running now */
Thread_timed_wait = 2,/* timed_waiting in object. Wait ()*/
Thread_monitor = 3,/* blocked on a monitor */
Thread_wait = 4,/* Waiting in object. Wait ()*/
Thread_initializing = 5,/* allocated, not yet running */
Thread_starting = 6,/* started, not yet on thread list */
Thread_native = 7,/* off in a jni native method */
Thread_vmwait = 8,/* waiting on a VM resource */
Thread_suincluded = 9,/* suincluded, usually by GC or debugger */

5. ANR case

5.1 ANR caused by UI thread Block

Mainhandler post runnable executes the loading of all installed app information in ANR on some mobile phones, because mainhandler post runnable runs in the UI thread, loading information of all installed apps will design a lot of parsing calculations, resulting in Ui callback timeout.

----- PID 2848 at 17:01:29 -----
Cmd Line: COM. Tencent. qfilemanager

Dalvik threads:
(Mutexes: tll = 0 TSL = 0 tscl = 0 ghl = 0)
"Main" PRIO = 5 tid = 1 native
| Group = "Main" scount = 1 dscount = 0 OBJ = 0x40cc3538 self = 0xabdf30
| Shard id = 2848 nice = 0 sched = 0/0 CRL = default handle = 1074267496
| Schedstat = (0 0 0) UTM = 64 STM = 58 core = 1
At Android. content. res. assetmanager. getstringblockcount (native method)
At Android. content. res. assetmanager. makestringblocks (assetmanager. Java: 257)
At Android. content. res. assetmanager. ensurestringblocks (assetmanager. Java: 249)
At Android. content. res. Resources. <init> (resources. Java: 206)
At Android. App. activitythread. gettoplevelresources (activitythread. Java: 1492)
At Android. App. activitythread. gettoplevelresources (activitythread. Java: 1519)
At Android. App. applicationpackagemanager. getresourcesforapplication (applicationpackagemanager. Java: 689)
At Android. App. applicationpackagemanager. gettext (applicationpackagemanager. Java: 891)
At Android. content. PM. packageiteminfo. loadlabel (packageiteminfo. Java: 115)
At com. Tencent. qfilemanager. fileanalysis. pkginfo. reloadpkginfo (pkginfo. Java: 50)
At com. Tencent. qfilemanager. fileanalysis. pkgcache.Loadallinstalledpackages(Pkgcache. Java: 29)
At com. Tencent. qfilemanager. activity.Filemanageractivity $ 3.run(Filemanageractivity. Java: 209)
At Android. OS. handler. handlecallback (handler. Java: 605)
At Android. OS. handler. dispatchmessage (handler. Java: 92)
At Android. OS. lorule. Loop (lorule. Java: 137)
At Android. App. activitythread. Main (activitythread. Java: 4456)
At java. Lang. Reflect. method. invokenative (native method)
At java. Lang. Reflect. method. Invoke (method. Java: 511)
At com. Android. Internal. OS. zygoteinit $ methodandargscaller. Run (zygoteinit. Java: 787)
At com. Android. Internal. OS. zygoteinit. Main (zygoteinit. Java: 554)
At Dalvik. system. nativestart. Main (native method)

5.2 ANR caused by high UI thread iowait

Batch database operations in onpostexecute of asynctask, resulting in ANR. Cause: the onpostexecute of asynctask is executed in the UI thread. Batch database operations are I/O operations, which are slow and the UI thread callback times out.

Process: COM. Android. Email
Activity: COM. Android. Email/. activity. messageview
Subject: keydispatchingtimedout
CPU usage from 2550 ms to-2814 Ms ago:
5% 187/system_server: 3.5% user + 1.4% kernel/faults: 86 minor 20 major
4.4% 1134/COM. Android. Email: 0.7% user + 3.7% kernel/faults: 38 minor 19 major
4% 372/COM. Android. eventstream: 0.7% user + 3.3% kernel/faults: 6 minor
1.1% 272/COM. Android. Phone: 0.9% user + 0.1% kernel/faults: 33 minor
0.9% 252/COM. Android. systemui: 0.9% user + 0% Kernel
0% 409/COM. Android. eventstream. telephonyplugin: 0% user + 0% kernel/faults: 2 minor
0.1% 632/COM. Android. devicemonitor: 0.1% user + 0% Kernel
100% total: 6.9% user + 8.2% kernel +84% iowait
----- PID 1134 at 17:46:51 -----
Cmd Line: COM. Android. Email
Dalvik threads:
(Mutexes: tll = 0 TSL = 0 tscl = 0 ghl = 0 hwl = 0 hwll = 0)
"Main" PRIO = 5 tid = 1 wait
| Group = "Main" scount = 1 dscount = 0 OBJ = 0x2aaca180self = 0xcf20
| Shard id = 1134 nice = 0 sched = 0/0 RGPS = [fopen-error: 2] handle = 1876218976
At java. Lang. Object. Wait (native method)
-Waiting on <0x2aaca218> (a java. Lang. vmthread)
Atjava. Lang. thread. parkfor (thread. Java: 1424)
...
Atandroid. database. SQLite. sqlitedatabase. Query (sqlitedatabase. Java: 1271)
Atcom. Android. Email. provider. emailprovider. Query (emailprovider. Java: 1098)
Atandroid. content. contentprovider $ transport. Query (contentprovider. Java: 187)
Atandroid. content.Contentresolver. Query(Contentresolver. Java: 268)
Atcom. Android. Email. provider. emailcontent $ message. restoremessagewithid (emailcontent. Java: 648)
Atcom. Android. Email. Controller. setmessageread (controller. Java: 658)
Atcom. Android. Email. activity. messageview. onmarkasread (messageview. Java: 700)
Atcom. Android. Email. activity. messageview. Access $2500 (messageview. Java: 98)
AtCom. Android. Email. activity. messageview $ loadbodytask. Onpostexecute(Messageview. Java: 1290)
Atcom. Android. Email. activity. messageview $ loadbodytask. onpostexecute (messageview. Java: 1255)
Atandroid. OS. asynctask. Finish (asynctask. Java: 417)
Atandroid. OS. asynctask. Access $300 (asynctask. Java: 127)
AtAndroid. OS.Asynctask$ Internalhandler. handlemessage(Asynctask. Java: 429)
Atandroid. OS. handler. dispatchmessage (handler. Java: 99)
Atandroid. OS. lorule. Loop (lorule. Java: 123)
Atandroid. App. activitythread. Main (activitythread. Java: 3652)
Atjava. Lang. Reflect. method. invokenative (native method)
Atjava. Lang. Reflect. method. Invoke (method. Java: 507)
Atcom. Android. Internal. OS. zygotein