Android ANR solution case (internal information)

Android ANR solution case (internal information)

When ANR occurs, you first need to view the log information and trace file (the system will generate a trace file in the/data/anr/directory) to analyze the cause of ANR. The following analysis does not solve all the ANR problems encountered, but the ANR problems caused by the program itself can basically find the cause.

Log Information Analysis

I/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 -- interface I/WindowManager (220): Input event dispatching timedout sendingtocom. android. email/com. android. email. activity. splitScreenActivity -- the ANR type (KeyDispatchTimeout (5 seconds) and BroadcastTimeout (1 0 seconds), ServiceTimeout (20 seconds) I/Process (220): Sending signal. PID: 21404 SIG: 3---trace.txt generation time I/dalvikvm (21404): threadid = 4: reacting to signal 3 ...... E/ActivityManager (220): ANR in com. android. email (com. android. email /. activity. splitScreenActivity) E/ActivityManager (220): Reason: keyDispatchingTimedOutE/ActivityManager (220): Load: 8.68/8.37/8.53E/ActivityManager (220 ): CPUusage from 4361 ms to 699 ms ago ---- CPU usage before ANR occurrence E/ActivityManager (220): 5.5! 404/com. android. email: 1.3% user + 4.1% kernel/faults: 10 minorE/ActivityManager (220): 4.3 "0/system_server: 2.7% user + 1.5% kernel/faults: 11 minor 2 majorE/ActivityManager (220): 0.9R/spi_qsd.0: 0% user + 0.9% kernelE/ActivityManager (220): 0.5e/irq/170-cyttsp -: 0% user + 0.5% kernelE/ActivityManager (220): 0.5) 6/com. android. systemui: 0.5% user + 0% kernelE/ActivityManager (220): 100% TOTAL: 4.8% user + 7.6% kernel + 87% iowaitE/ActivityManager (220): CPUusage from 3697 ms to 4223 ms later: -- CPU usage after anr e/ActivityManager (220): 25! 404/com. android. email: 25% user + 0% kernel/faults: 191 minorE/ActivityManager (220): 16% 21603/_ eas (par. hakan: 16% user + 0% kernelE/ActivityManager (220): 7.2% 21406/GC: 7.2% user + 0% kernelE/ActivityManager (220): 1.8% 21409/Compiler: 1.8% user + 0% kernelE/ActivityManager (220): 5.5 "0/system_server: 0% user + 5.5% kernel/faults: 1 minorE/ActivityManager (220): 5.5% 263/InputDispatcher: 0% user + 5.5% kernelE/ActivityManager (220): 32% TOTAL: 28% user + 3.7% kernel

From the LOG, we can see the ANR type and CPU usage. If the CPU usage is close to 100%, it indicates that the current device is very busy and may be caused by CPU hunger.

If the CPU usage is small, the main thread is blocked.

If IOwait is high, it indicates that ANR may be caused by the I/O operation of the main thread.

After reading the logstore, The anrstill has the trace.txt file,

Trace File Analysis

Pid 21404 at 2011-04-011:----- using line: com. android. emailDALVIK THREADS :( mutexes: tll = 0tsl = 0 tscl = 0 ghl = 0 hwl = 0 hwll = 0) "main" prio = 5 tid = 1 NATIVE -- indicates the thread status (/? Dalvik /? Vm /? Thread. h0042 enum ThreadStatus {0043 THREAD_UNDEFINED =-1,/* makes enum compatible with int32_t */0045/* these match up with JDWP values */0046 THREAD_ZOMBIE = 0, /* TERMINATED */0047 THREAD_RUNNING = 1,/* RUNNABLE or running now */0048 THREAD_TIMED_WAIT = 2,/* TIMED_WAITING in Object. wait () */0049 THREAD_MONITOR = 3,/* BLOCKED on a monitor */0050 THREAD_WAIT = 4,/* WAITING in Object. wait () */0051/* non-JDWP states */0052 THREAD_INITIALIZING = 5,/* allocated, not yet running */0053 THREAD_STARTING = 6,/* started, not yet on thread list */0054 THREAD_NATIVE = 7,/* off in a JNI native method */0055 THREAD_VMWAIT = 8, /* waiting on a VM resource */0056 thread_susponded = 9,/* suincluded, usually by GC or debugger */0057 };) | group = "main" sCount = 1 dsCount = 0obj = 0x2aad2248 self = 0xcf70 | shard id = 21404 nice = 0 sched = 0/0 fk= [fopen-error: 2] handle = 1876218976atandroid. OS. messageQueue. nativePollOnce (Native Method) atandroid. OS. messageQueue. next (MessageQueue. java: 119) atandroid. OS. logoff. loop (logoff. java: 110) at android. app. activityThread. main (ActivityThread. java: 3688) at java. lang. reflect. method. invokeNative (Native Method) atjava. lang. reflect. method. invoke (Method. java: 507) atcom. 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)

The main thread is waiting for the next message to enter the message queue.

We can clearly parse the meaning of the thread information in the trace file:

1. The first line is a Fixed Header, indicating that all of the following are currently running dvm THREADS: "dalvik threads :"

2. The second line outputs the mutex values of various threads in the process. (The specific mutex function is stated separately in the dalvik thread chapter)

3. the output in the third row is the thread name ("main"), thread priority ("prio = 5"), and thread id ("tid = 1 ") and the thread type ("NATIVE ")

Case

Case 1: keywords: ContentResolver in AsyncTask onPostExecute, high iowait

Process:com.android.emailActivity:com.android.email/.activity.MessageViewSubject:keyDispatchingTimedOutCPU usage from 2550ms to -2814ms ago:57/system_server: 3.5% user + 1.4% kernel / faults: 86 minor 20major4.4% 1134/com.android.email: 0.7% user + 3.7% kernel /faults: 38 minor 19 major4% 372/com.android.eventstream: 0.7%user + 3.3% kernel / faults: 6 minor1.1% 272/com.android.phone:0.9% user + 0.1% kernel / faults: 33 minor0.9%2/com.android.systemui: 0.9% user + 0% kernel0@9/com.android.eventstream.telephonyplugin: 0% user + 0% kernel /faults: 2 minor0.1% 632/com.android.devicemonitor: 0.1% user + 0%kernel100%TOTAL: 6.9% user + 8.2% kernel +84%iowait pid 1134 at 2010-12-17 17:46:51 -----Cmd line:com.android.emailDALVIK THREADS:(mutexes: tll=0 tsl=0tscl=0 ghl=0 hwl=0 hwll=0)"main" prio=5 tid=1 WAIT|group="main" sCount=1 dsCount=0 obj=0x2aaca180self=0xcf20| sysTid=1134 nice=0 sched=0/0 cgrp=[fopen-error:2]handle=1876218976at java.lang.Object.wait(Native Method)-waiting on <0x2aaca218> (a java.lang.VMThread)atjava.lang.Thread.parkFor(Thread.java:1424)atjava.lang.LangAccessImpl.parkFor(LangAccessImpl.java:48)atsun.misc.Unsafe.park(Unsafe.java:337)atjava.util.concurrent.locks.LockSupport.park(LockSupport.java:157)atjava.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:808)atjava.util.concurrent.locks.AbstractQueuedSynchronizer.acquireQueued(AbstractQueuedSynchronizer.java:841)atjava.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(AbstractQueuedSynchronizer.java:1171)atjava.util.concurrent.locks.ReentrantLock$FairSync.lock(ReentrantLock.java:200)atjava.util.concurrent.locks.ReentrantLock.lock(ReentrantLock.java:261)atandroid.database.sqlite.SQLiteDatabase.lock(SQLiteDatabase.java:378)atandroid.database.sqlite.SQLiteCursor.
 
  (SQLiteCursor.java:222)atandroid.database.sqlite.SQLiteDirectCursorDriver.query(SQLiteDirectCursorDriver.java:53)atandroid.database.sqlite.SQLiteDatabase.rawQueryWithFactory(SQLiteDatabase.java:1356)atandroid.database.sqlite.SQLiteDatabase.queryWithFactory(SQLiteDatabase.java:1235)atandroid.database.sqlite.SQLiteDatabase.query(SQLiteDatabase.java:1189)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.Looper.loop(Looper.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
 

Cause: IOWait is very high, indicating that the current system is busy with I/O, so database operations are blocked

Case 2: keywords: Network Data Reading and Writing in the UI thread

ANRin process: com.android.mediascape:PhotoViewer (last incom.android.mediascape:PhotoViewer)Annotation:keyDispatchingTimedOutCPU usage:Load: 6.74 / 6.89 / 6.12CPUusage from 8254ms to 3224ms ago:ovider.webmedia: 4% = 4% user +0% kernel / faults: 68 minorsystem_server: 2% = 1% user + 0%kernel / faults: 18 minorre-initialized>: 0% = 0% user + 0%kernel / faults: 50 minorevents/0: 0% = 0% user + 0%kernelTOTAL:7% = 6% user + 1% kernelDALVIKTHREADS:""main"" prio=5 tid=3 NATIVE|group=""main"" sCount=1 dsCount=0 s=Yobj=0x4001b240 self=0xbda8| sysTid=2579 nice=0 sched=0/0cgrp=unknown handle=-1343993184atorg.apache.harmony.luni.platform.OSNetworkSystem.receiveStreamImpl(NativeMethod)atorg.apache.harmony.luni.platform.OSNetworkSystem.receiveStream(OSNetworkSystem.java:478)atorg.apache.harmony.luni.net.PlainSocketImpl.read(PlainSocketImpl.java:565)atorg.apache.harmony.luni.net.SocketInputStream.read(SocketInputStream.java:87)atorg.apache.harmony.luni.internal.net.www.protocol.http.HttpURLConnection$LimitedInputStream.read(HttpURLConnection.java:303)atjava.io.InputStream.read(InputStream.java:133)atjava.io.BufferedInputStream.fillbuf(BufferedInputStream.java:157)atjava.io.BufferedInputStream.read(BufferedInputStream.java:346)atandroid.graphics.BitmapFactory.nativeDecodeStream(Native Method)atandroid.graphics.BitmapFactory.decodeStream(BitmapFactory.java:459)atcom.android.mediascape.activity.PhotoViewerActivity.getPreviewImage(PhotoViewerActivity.java:4465)atcom.android.mediascape.activity.PhotoViewerActivity.dispPreview(PhotoViewerActivity.java:4406)atcom.android.mediascape.activity.PhotoViewerActivity.access$6500(PhotoViewerActivity.java:125)atcom.android.mediascape.activity.PhotoViewerActivity$33$1.run(PhotoViewerActivity.java:4558)atandroid.os.Handler.handleCallback(Handler.java:587)atandroid.os.Handler.dispatchMessage(Handler.java:92)atandroid.os.Looper.loop(Looper.java:123)atandroid.app.ActivityThread.main(ActivityThread.java:4370)atjava.lang.reflect.Method.invokeNative(Native Method)atjava.lang.reflect.Method.invoke(Method.java:521)atcom.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:868)atcom.android.internal.os.ZygoteInit.main(ZygoteInit.java:626)atdalvik.system.NativeStart.main(Native Method)

For network connections, you can set a timeout time or put it into an independent thread for processing during design.

For Handler problems, you can refer to: http://developer.android.com/reference/android/ OS /Handler.html

Case 3: Memoryleak/Thread leak

I/ActivityManager( 1190): ANR in process:android.process.acore (last in android.process.acore)I/ActivityManager( 1190): Annotation:keyDispatchingTimedOutI/ActivityManager(1190): CPU usage:I/ActivityManager( 1190):Load: 11.5 / 11.1 / 11.09I/ActivityManager(1190): CPU usage from 9046ms to 4018ms ago:I/ActivityManager( 1190): d.process.acore:98% = 97% user + 0% kernel / faults: 1134 minorI/ActivityManager( 1190): system_server: 0% = 0% user + 0% kernel /faults: 1 minorI/ActivityManager( 1190): adbd:0% = 0% user + 0% kernelI/ActivityManager(1190): logcat: 0% = 0% user + 0% kernelI/ActivityManager( 1190): TOTAL:100% = 98% user + 1% kernelCmdline: android.process.acoreDALVIK THREADS:"main"prio=5 tid=3 VMWAIT|group="main" sCount=1 dsCount=0 s=N obj=0x40026240self=0xbda8| sysTid=1815 nice=0 sched=0/0 cgrp=unknownhandle=-1344001376atdalvik.system.VMRuntime.trackExternalAllocation(NativeMethod)atandroid.graphics.Bitmap.nativeCreate(Native Method)atandroid.graphics.Bitmap.createBitmap(Bitmap.java:468)atandroid.view.View.buildDrawingCache(View.java:6324)atandroid.view.View.getDrawingCache(View.java:6178)atandroid.view.ViewGroup.drawChild(ViewGroup.java:1541)……atcom.android.internal.policy.impl.PhoneWindow$DecorView.draw(PhoneWindow.java:1830)atandroid.view.ViewRoot.draw(ViewRoot.java:1349)atandroid.view.ViewRoot.performTraversals(ViewRoot.java:1114)atandroid.view.ViewRoot.handleMessage(ViewRoot.java:1633)atandroid.os.Handler.dispatchMessage(Handler.java:99)atandroid.os.Looper.loop(Looper.java:123)atandroid.app.ActivityThread.main(ActivityThread.java:4370)atjava.lang.reflect.Method.invokeNative(Native Method)atjava.lang.reflect.Method.invoke(Method.java:521)atcom.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:868)atcom.android.internal.os.ZygoteInit.main(ZygoteInit.java:626)atdalvik.system.NativeStart.main(Native Method)"Thread-408"prio=5 tid=329 WAIT|group="main" sCount=1 dsCount=0 s=N obj=0x46910d40self=0xcd0548| sysTid=10602 nice=0 sched=0/0 cgrp=unknownhandle=15470792at java.lang.Object.wait(Native Method)-waiting on <0x468cd420> (a java.lang.Object)atjava.lang.Object.wait(Object.java:288)atcom.android.dialer.CallLogContentHelper$UiUpdaterExecutor$1.run(CallLogContentHelper.java:289)atjava.lang.Thread.run(Thread.java:1096)

Analysis:
Atdalvik. system. VMRuntime. trackExternalAllocation (NativeMethod) Insufficient memory causes the block to be created on the bitmap.
* MEMINFO in pid 1360 [android. process. acore] *
Native dalvik other total

Size: 17036 23111 N/A 40147
Allocated: 16484 20675 N/A 37159
Free: 296 2436 N/A 2732

Solution: if the memory family of the machine is used, you can change the memory size of the virtual machine to 36 MB or larger, but it is best to review the code to check which memory has not been released.