Android ANR analysis

Introduce ANR

ANR, which is short for “Application Not Responding,” or “Application Not Responding.” A dialog box is presented to the user, and the user can choose to “wait” and let the program continue, or “force shutdown.”

ANR condition occurs

Events that do not respond to input within 5 seconds (e.g. key press, screen touch)
The BroadcastReceiver did not finish executing for 10 seconds
The Service could not complete processing for a specific period of time (20 seconds)

ANR can be caused by time-consuming operations on the main thread, such as network connections, I/O reads and writes, and thread synchronization locks. Note that this ANR is generated only when there is an input event. If the user does not trigger any input event, the ANR will not be generated even if the main thread is blocked.

Take a look at some sample code

public class AnrActivity extends Activity {
    @Override
    protected void onCreate(@Nullable Bundle savedInstanceState) {
        super.onCreate(savedInstanceState);
        setContentView(R.layout.content_main);

        start();
    }
    private synchronized void start(a) {
        try {
            while (true) {
                Thread.sleep(10000); }}catch(InterruptedException e) { e.printStackTrace(); }}}Copy the code

Does ANR occur at startup? No, because there are no input events
Will ANR occur when you hit the back button? will

How do I obtain ANR logs

Old version system

ANR logs are stored in data/ ANR/localted.txt
adb shell cat /data/anr/traces.txt > /… / localted. TXT can export log files

New Version system

/data/anr/ localted. TXT /data/anr/ localted. TXT /data/anr/ localted. TXT /data/anr/ localted. TXT
Use ADB bugreport <zip_file> to generate a zip file named zip_file in the computer’s current directory

Analyze ANR logs

The process ID, time, and process name for the first two lines of ANR.

----- pid 24277 at 2019-09-16 16:23:19 -----
Cmd line: com.example.androidtest
Copy the code

Information such as memory

Build fingerprint: 'Google/walleye/walleye: 9 / PQ1A 190105.004/5148680: user/release - keys'
ABI: 'arm64'
Build type: optimized
Zygote loaded classes=10643 post zygote classes=81
Intern table: 73306 strong; 365 weak
JNI: CheckJNI is on; globals=602 (plus 23 weak)
Libraries: /system/lib64/libandroid.so /system/lib64/libcompiler_rt.so /system/lib64/libjavacrypto.so /system/lib64/libjnigraphics.so /system/lib64/libmedia_jni.so /system/lib64/libsoundpool.so /system/lib64/libwebviewchromium_loader.so libjavacore.so libopenjdk.so (9)
Heap: 33% free, 1760KB/2MB; 42897 objects
......
suspend all histogram:	Sum: 133us 99% C.I. 1us-46us Avg: 8.866us Max: 46us
Copy the code

Specific thread information

"Signal Catcher" daemon prio=5 tid=3 Runnable | group="system" sCount=0 dsCount=0 flags=0 obj=0x13dc0000 self=0x78a0a16400 | sysTid=24283 nice=0 cgrp=default sched=0/0 handle=0x789a1ff4f0 | state=R schedstat=( 11415990 257604  4 ) utm=0 stm=0 core=6 HZ=100 | stack=0x789a104000-0x789a106000 stackSize=1009KB | held mutexes= "mutator lock"(shared held) native: #00 pc 00000000003c7324 /system/lib64/libart.so (art::DumpNativeStack(std::__1::basic_ostream<char, std::__1::char_traits<char>>&, int, BacktraceMap*, char const*, art::ArtMethod*, void*, bool)+220) native: #01 pc 0000000000495d80 /system/lib64/libart.so (art::Thread::DumpStack(std::__1::basic_ostream<char, std::__1::char_traits<char>>&, bool, BacktraceMap*, bool) const+352) native: #02 pc 00000000004afd1c /system/lib64/libart.so (art::DumpCheckpoint::Run(art::Thread*)+844) native: #03 pc 00000000004a8a5c /system/lib64/libart.so (art::ThreadList::RunCheckpoint(art::Closure*, art::Closure*)+476) native: #04 pc 00000000004a7eac /system/lib64/libart.so (art::ThreadList::Dump(std::__1::basic_ostream<char, std::__1::char_traits<char>>&, bool)+1036) native: #05 pc 00000000004a79b4 /system/lib64/libart.so (art::ThreadList::DumpForSigQuit(std::__1::basic_ostream<char, std::__1::char_traits<char>>&)+884) native: #06 pc 0000000000477864 /system/lib64/libart.so (art::Runtime::DumpForSigQuit(std::__1::basic_ostream<char, std::__1::char_traits<char>>&)+188) native: #07 pc 000000000048372c /system/lib64/libart.so (art::SignalCatcher::HandleSigQuit()+1372) native: #08 pc 0000000000482420 /system/lib64/libart.so (art::SignalCatcher::Run(void*)+256) native: #09 pc 0000000000083194 /system/lib64/libc.so (__pthread_start(void*)+36) native: #10 pc 00000000000233bc /system/lib64/libc.so (__start_thread+68) (no managed stack frames)Copy the code

instructions

The first line

Thread name (daemons if present)

Prio: indicates the priority of a thread

Dar: thread number

The current status of the thread Runnable

The second line

Group: indicates the thread group to which the thread belongs

SCount: indicates the number of times the thread is suspended

DsCount: The number of times the thread is suspended for debugging

Obj: Java thread object associated with the current thread

Self: address of the current thread

The third line

SysTid: the tid of a thread

Nice: scheduling priority A smaller nice value indicates a higher priority

CGRP: scheduling group to which a thread belongs

Sched: scheduling policy

Handle: address of function processing

In the fourth row

State: indicates the status of the thread

Schedstat: CPU scheduling time statistics

The three numbers in the schedstat brackets are Running, Runable, Switch,

Running time: indicates the CPU Running time, in ns
Runable time: wait time of the RQ queue, in ns
Switch times: indicates the number of CPU scheduling switches

Utm/STM: CPU time in user/kernel mode

Utm: time for the thread to execute in user mode, in jiffies. Jiffies are defined as sysconf(_SC_CLK_TCK), and the default value is 10ms.

STM: the time for the thread to execute in kernel mode, in jiffies. The default value is 10ms.

Utm + STM = schedstat first parameter value.

Core: the core in which the thread was last run

HZ: clock frequency

The fifth row

Stack: address range of the thread stack

StackSize: indicates the stackSize

The sixth line

Mutex: The muTEX type is exclusive and shared

Analyze ANR logs

Start by simulating a code that causes ANR

public class AnrActivity extends Activity {
    @Override
    protected void onCreate(@Nullable Bundle savedInstanceState) {
        super.onCreate(savedInstanceState);
        setContentView(R.layout.content_main);

        findViewById(R.id.txt).setOnClickListener(new View.OnClickListener() {
            @Override
            public void onClick(View v) { stop(); }});new Thread(new Runnable() {
            @Override
            public void run(a) {
                start();
            }
        }).start();
    }

    private synchronized void start(a) {
        long startTime = System.currentTimeMillis();
        while (true) {
            long stopTime = System.currentTimeMillis();
            if ((stopTime - startTime) / 1000> =10) {
                break; }}}private synchronized void stop(a) {
        Toast.makeText(AnrActivity.this."stop", Toast.LENGTH_SHORT).show(); }}Copy the code

"main" prio=5 tid=1 Blocked
  | group="main" sCount=1 dsCount=0 flags=1 obj=0x75586910 self=0x78a0a14c00
  | sysTid=24277 nice=-10 cgrp=default sched=0/0 handle=0x79264f2548
  | state=S schedstat=( 289217601 7166871 217 ) utm=25 stm=3 core=6 HZ=100
  | stack=0x7fe93cd000-0x7fe93cf000 stackSize=8MB
  | held mutexes=
  at com.example.androidtest.anr.AnrActivity.stop(AnrActivity.java:-1)
  - waiting to lock <0x06b3ced2> (a com.example.androidtest.anr.AnrActivity) held by thread 13
  at com.example.androidtest.anr.AnrActivity.access$000(AnrActivity.java:12)
  at com.example.androidtest.anr.AnrActivity$1.onClick(AnrActivity.java:21)
  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)
Copy the code

“Main” prio=5 TID =1 Blocked The main thread is Blocked
By mutexes = at com. Example. Androidtest. Anr. AnrActivity. Stop (AnrActivity. Java: 1) anr in stop method
Waiting to lock < 0 x06b3ced2 > (a com. Example. Androidtest. Anr. AnrActivity) by 13 in the thread by thread lock 13 < 0 x06b3ced2 > and wait

We know that tid stands for thread ID, so find information about the thread where tid=13

"Thread-2" prio=5 tid=13 Suspended
  | group="main" sCount=1 dsCount=0 flags=1 obj=0x12c7ae18 self=0x78a0af1800
  | sysTid=24295 nice=0 cgrp=default sched=0/0 handle=0x788a5ff4f0
  | state=S schedstat=( 7380427077 3743221 140 ) utm=737 stm=0 core=5 HZ=100
  | stack=0x788a4fc000-0x788a4fe000 stackSize=1041KB
  | held mutexes=
  at com.example.androidtest.anr.AnrActivity.start(AnrActivity.java:35)
  - locked <0x06b3ced2> (a com.example.androidtest.anr.AnrActivity)
  at com.example.androidtest.anr.AnrActivity.access$100(AnrActivity.java:12)
  at com.example.androidtest.anr.AnrActivity$2.run(AnrActivity.java:27)
  at java.lang.Thread.run(Thread.java:764)
Copy the code

<0x06b3ced2> is locked in the start method.

Introduce ANR

ANR condition occurs

How do I obtain ANR logs

Old version system

New Version system

Analyze ANR logs

instructions

Analyze ANR logs

Related Posts

My spring journey in mobile development

Android Shortcuts: Hold down the APP icon to pop-up Shortcuts

Property inspection and anti-cheating scene based on Tencent location service positioning