APP not responsing

See Original: http://rayleeya.iteye.com/blog/1955657

• Inputdispatchingtimedout
• Contentprovidernotresponsing
• Servicetimedout
• Broadcastreceivertimedout

The trace information is output to "/data/anr/traces.txt", which is configured by the system Properties "Dalvik.vm.stack-trace-file", which can be obtained through getprop in the ADB shell. can also be set by SetProp.

Traces.txt Information Detailed:

The trace information of the first process that is output in the file is exactly what happens to the ANR demo program

The beginning shows the process number, the time point of the ANR occurrence, and the process name

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

CMD Line:com.example.anrdemo

DALVIK THREADS: //The following is the function stack information for each thread

Mutexes represents the value values of various thread-related object locks in a virtual machine instance

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

In order: Thread name, thread priority, sequence number when thread is created, ① thread's current state

"Main" prio=5 tid=1 timed_wait

In order: Thread group name, Suspendcount, Debugsuspendcount, Java object address of thread, native object address of thread

| group= "main" scount=1 dscount=0 obj=0x4025b1b8 self=0xce68

Systid is the thread number, the thread number and the process number of the main thread are the same

| 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)

The binder thread is the thread in the thread pool of the process used to process binder requests, which should be Viewroot's W class for IPC communication with the WMS

"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)

Should be Activitythread's Applicationthread binder thread for IPC communication with AMS

"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)

The thread name is followed by a daemon, which indicates that this is a daemon thread

"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 threads are threads that support virtual machine debugging and do not need to be concerned

"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" is responsible for receiving and processing various signals kernel send, such as Signal_quit, SIGNAL_USR1, etc. is the thread

Received, the content of this file is the thread responsible for output, you can see its state is runnable, but this thread does not need to care

"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

... ...

Omit information from other processes

There is a key point to note:

? Threads have many states, and understanding the meaning of these states is helpful for analyzing the causes of ANR, as summarized below:

States defined in the Thread.java	States defined in the Thread.cpp	Description
TERMINATED	ZOMBIE	Thread dead, terminating run
RUNNABLE	Running/runnable	Thread can run or is running
Timed_waiting	Timed_wait	Wait, sleep, or join functions with time-out parameters executed
BLOCKED	MONITOR	Thread blocking, waiting to get object lock
Waiting	WAIT	Execute the wait function without a timeout parameter
NEW	INITIALIZING	New, initializing, assigning resources to it
NEW	Starting	New, starting
RUNNABLE	NATIVE	Executing JNI local function
Waiting	Vmwait	Waiting for VM Resources
RUNNABLE	SUSPENDED	Thread paused, usually because the GC or debug is paused
	UNKNOWN	Unknown status

The state in the Thread.java has a corresponding relationship with the state in the Thread.cpp. You can see that the former is more generalized and easier to understand, for Java-oriented users, while the latter is more detailed for the internal environment of the virtual machine. The thread state shown in Traces.txt is defined in Thread.cpp. In addition, all threads are local threads that follow the POSIX standard. More instructions on threading can be found in the source/dalvik/vm/thread.cpp instructions. <!--thread Threadgroup It's best to write it in.

This information in the Traces.txt file is output by the signalcatcher thread of each Dalvik process, and the relevant code can see SignalCatcher.cpp in the/dalvik/vm/directory: Logthreadstacks function and Thread.cpp:: Dvmdumpallthreadsex function. Also note that signalcatcher suspends all threads when the stack information is output.

It is easy to know how the main thread of the problem process is doing when the ANR occurs. For example, in the example above, anractivity occurs when a thread sleep is performed in the MAKEANR function, and it can be inferred that the sleep time is too long and exceeds the timeout limit. This is a relatively simple situation, the actual development will encounter a lot of strange, more complex situation, in the following example explained in detail in the section.

Log information Details:

The process where the WindowManager is located is System_server, and the process number is 127

I/windowmanager (127): Input event dispatching timed out sending to com.example.anrdemo/com.example.anrdemo.anractivity

The Activitymanagerservice request kernel in the System_server process sends a SIGNAL_QUIT request to the 5033 process

You can use commands in the shell to achieve the same purpose: adb shell kill-3 5033

Like other Java virtual machines, Signal_quit is also one of the features that Dalvik internally supports

I/process (127): Sending signal. pid:5033 Sig:3

5033 the process's virtual machine instance receives the SIGNAL_QUIT signal and outputs the function stack information from each thread in the process to the Traces.txt file

The process in which the ANR occurs normally will be the first output

I/DALVIKVM (5033): Threadid=4:reacting to signal 3

I/DALVIKVM (5033): wrote stack traces to '/data/anr/traces.txt '

...//There are other processes

CPU usage is then output

E/activitymanager (127): ANR in Com.example.anrdemo (com.example.anrdemo/. anractivity)

Reason indicates the direct cause of the ANR problem

E/activitymanager (127): Reason:keydispatchingtimedout

E/activitymanager (127): load:3.85/3.41/3.16

Note ago, which indicates the CPU usage over a period of time before the ANR occurs, is not a value for a certain moment

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

Here is later, indicating that after the ANR occurred

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