Android - How to Investigate an Anr

Android - how do I investigate an ANR?

An ANR happens when some long operation takes place in the "main" thread. This is the event loop thread, and if it is busy, Android cannot process any further GUI events in the application, and thus throws up an ANR dialog.

Now, in the trace you posted, the main thread seems to be doing fine, there is no problem. It is idling in the MessageQueue, waiting for another message to come in. In your case the ANR was likely a longer operation, rather than something that blocked the thread permanently, so the event thread recovered after the operation finished, and your trace went through after the ANR.

Detecting where ANRs happen is easy if it is a permanent block (deadlock acquiring some locks for instance), but harder if it's just a temporary delay. First, go over your code and look for vunerable spots and long running operations. Examples may include using sockets, locks, thread sleeps, and other blocking operations from within the event thread. You should make sure these all happen in separate threads. If nothing seems the problem, use DDMS and enable the thread view. This shows all the threads in your application similar to the trace you have. Reproduce the ANR, and refresh the main thread at the same time. That should show you precisely whats going on at the time of the ANR

How to debug Android ANR?

But how to know where it is blocked?

Start by enabling StrictMode and running your app. If you (or Analytics) are doing disk or network I/O on the main application thread, you will find out about it, based upon your chosen penalty style (e.g., log in LogCat):

public void onCreate() {
     if (BuildConfig.DEBUG) {
         StrictMode.setThreadPolicy(new StrictMode.ThreadPolicy.Builder()
                 .detectAll()
                 .penaltyLog()
                 .build());
     }

     super.onCreate();

     // rest of onCreate() logic here
 }

Find out the reason of ANR using Android Profiler

Finally I have found the problem which was nothing to do about the codes that I shared.

In the project a service is started but did not set the notification like startForeground(ID, notification). It was not showing in the logs. When I choose the Information level logs I saw the cause which was

E/ActivityManager: ANR in PID: 6516 Reason: Context.startForegroundService() did not then call Service.startForeground() It was an unnecessary service call so I commented that and the ANR dialog is disappeared.

How can I find out which parts of my code are using the UI Thread the most?

First thing you can do is enable StrictMode. That will detect non-UI, potentially long operations running on the main thread.

Second thing you can do is profile the CPU, as stated above. You'll be able to see the activity per thread, so you can determine what is running where. In order to get accurate readings, don't run it from Android Studio. Run it directly from your code. The easiest way to do that is to use the Debug class, and start the sampling at the Application.onCreate && finish it when the app closes.

The third thing you can do is to observe the messages sent to the main thread looper and evaluate them. Pierre-Yves Ricau has a nice guide about this that you can adapt to your own processes.

After that, you can use custom approaches to evaluate critical parts of your code, like generating your own traces. Perfetto uses JSON files, so you can print logcat messages from the parts you suspect are causing trouble and parse those messages into a perfetto trace.

How to analyze an Android /data/anr/traces.txt file?

So far, it doesn't look like it has a problem. As we can observe here, The main thread is suspended and so is one more thread called WebViewCoreThread, apart from these 2 all others seem to be pretty alright either doing a classic wait or a timed wait or just running.

The 2 possible reasons why the ANR could have occurred here might be because either of the 2 threads is suspended indefinitely and the android (system) would have thought they have died , after waiting for some time out, say few seconds, thus throwing an ANR.

You might want to check if there are any break points in either of those threads or either of those threads are doing some heavy op involving instantiation of objects leading to gc which also might cause the thread to enter suspended mode.

Also check the logs for any sign on watchdog killing any of the system process.. might help fig this out!

How to avoid ANR From an app when it is not in the foreground?

From Google docs:

Android will display the ANR dialog for a particular application when it detects one of the following conditions:

• No response to an input event (such as key press or screen touch events) within 5 seconds.
• A BroadcastReceiver hasn't finished executing within 10 seconds.

After that be sure to not do blocking/long operations on the UiThread/MainThread even if the App is in background.

How to get something useful from this ANR log

You have thread dumps for multiple processes in there. To get to the useful part, you can search for "Cmd line" until you find your process ("cz.vcelka.androidapp", the pid was 21574).

If you get an ANR that means that your main thread is blocked somehow, so you should look at its stack trace. Here it is :

"main" prio=5 tid=1 Waiting
  | group="main" sCount=1 dsCount=0 obj=0x74bc2fa0 self=0xb4db6500
  | sysTid=21574 nice=0 cgrp=default sched=0/0 handle=0xb6fc1b34
  | state=S schedstat=( 0 0 0 ) utm=785 stm=88 core=1 HZ=100
  | stack=0xbe29a000-0xbe29c000 stackSize=8MB
  | held mutexes=
  at java.lang.Object.wait!(Native method)
  - waiting on <0x05853836> (a java.lang.Object)
  at java.lang.Thread.parkFor$(Thread.java:1220)
  - locked <0x05853836> (a java.lang.Object)
  at sun.misc.Unsafe.park(Unsafe.java:299)
  at java.util.concurrent.locks.LockSupport.park(LockSupport.java:158)
  at java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:810)
  at java.util.concurrent.locks.AbstractQueuedSynchronizer.doAcquireSharedInterruptibly(AbstractQueuedSynchronizer.java:971)
  at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireSharedInterruptibly(AbstractQueuedSynchronizer.java:1278)
  at java.util.concurrent.CountDownLatch.await(CountDownLatch.java:203)
  at android.app.SharedPreferencesImpl$EditorImpl$1.run(SharedPreferencesImpl.java:366)
  at android.app.QueuedWork.waitToFinish(QueuedWork.java:88)
  at android.app.ActivityThread.handleStopActivity(ActivityThread.java:3560)
  at android.app.ActivityThread.-wrap20(ActivityThread.java:-1)
  at android.app.ActivityThread$H.handleMessage(ActivityThread.java:1373)
  at android.os.Handler.dispatchMessage(Handler.java:102)
  at android.os.Looper.loop(Looper.java:148)
  at android.app.ActivityThread.main(ActivityThread.java:5417)
  at java.lang.reflect.Method.invoke!(Native method)
  at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:726)
  at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:616)

So your main thread is blocked waiting on a CountDownLatch inside SharedPreferences code. We can look at the source code of SharedPreferences to find out more. At some point when you called SharedPreferences.Editor.apply(), the SharedPreferences code enqueued the write to disk to a worker thread. It also called QueuedWork.add(awaitCommit), where awaitCommit is a Runnable that waits on the write operation (by means of CountDownLatch), and QueuedWork.add() is a method that enqueues work to be done on the main thread when the activity's onPause method is called. That is what happened : onPause was called, and now the main thread is stuck waiting on the worker thread to complete its write operation.

Now the problem is that the log you posted is incomplete. Several threads are missing, including the worker thread that never called CountDownLatch.countDown(), so it is not possible to tell what is causing the deadlock. If you post the whole log (for your process, I don't think the other ones are going to be useful), we can probably help more.

Edit : I noticed that someone else here ran into the same problem. For them, the worker thread was stuck in fsync(2). fsync can be really slow (as in multiple seconds) if the file is big and / or the disk is busy. I suppose that could be causing the ANR. I'm not sure if that would classify as a bug in SharedPreferences... Seems a bit weird to trigger possibly long blocking operations on the main thread, even if called from onPause... If this is indeed your problem, the only workaround I can think of would be to use commit() instead of apply(), since that will do the write synchronously. You should do it from a background thread, given that in your particular setup it seems that it can take a pretty long time to flush to disk !

Or maybe your SharedPreferences file is just way too big, in which case you could try slimming it down (by using a database for instance).

---

Related Topics