Android ANR 搜集

Android ANR排查

应用层一般如下情况下需要查看log
1) 程序异常退出， uncaused exception
2) 程序强制关闭，Force Closed (简称FC)
3) 程序无响应， Application No Response （简称ANR) ，顺便，一般主线程超过5秒么有处理就会ANR

Log文件的组成
1) 系统基本信息，包括内存，CPU ，进程队列，虚拟内存，垃圾回收等信息。
2) 时间信息，也是我们主要分析的信息。
3) 虚拟机信息，包括进程的，线程的跟踪信息，这是用来跟踪进程和线程具体点的好地方。

查看log的基本步骤
1) 如果是ANR问题，则搜索“ANR”关键词。快速定位到关键事件信息
2) 如果是ForceClosed 和其它异常退出信息，则搜索"Fatal" 关键词，快速定位到关键事件信息
3) 定位到关键事件信息后，如果信息不够明确的，再去搜索应用程序包的虚拟机信息，查看具体的进程和线程跟踪的日志，来定位到代码。

下面，我们就开始来分析这个例子的log 。

打开log文件，由于是ANR错误，因此搜索"ANR " ，为何要加空格呢，你加上和去掉比较一下就知道了。可以屏蔽掉不少保存到anr.log文件的无效信息。

定位到关键的事件信息如下：
01-15 16:49:02.433 E/ActivityManager( 2466): ANR in com.android.mms (com.android.mms/.ui.SlideshowActivity)
01-15 16:49:02.433 E/ActivityManager( 2466): Reason: keyDispatchingTimedOut
01-15 16:49:02.433 E/ActivityManager( 2466): Load: 0.6 / 0.61 / 0.42
01-15 16:49:02.433 E/ActivityManager( 2466): CPU usage from 1337225ms to 57ms ago:
01-15 16:49:02.433 E/ActivityManager( 2466): sensorserver_ya: 8% = 0% user + 8% kernel / faults: 40 minor
......

01-15 16:49:02.433 E/ActivityManager( 2466): -com.android.mms: 0% = 0% user + 0% kernel
01-15 16:49:02.433 E/ActivityManager( 2466): -flush-179:8: 0% = 0% user + 0% kernel
01-15 16:49:02.433 E/ActivityManager( 2466): TOTAL: 25% = 10% user + 14% kernel + 0% iowait + 0% irq + 0% softirq
01-15 16:49:02.436 I/ ( 2466): dumpmesg > "/data/log/dumpstate_app_anr.log"

我们用自然语言来描述一下日志，这也算是一种能力吧。
01-15 16:49:02.433 E/ActivityManager( 2466): ANR in com.android.mms (com.android.mms/.ui.SlideshowActivity)
翻译：在16:49分2秒433毫秒的时候 ActivityManager （进程号为2466) 发生了如下错误：com.android.mms包下面的.ui.SlideshowActivity 无响应。

01-15 16:49:02.433 E/ActivityManager( 2466): Reason: keyDispatchingTimedOut
翻译：原因， keyDispatchingTimeOut - 按键分配超时

01-15 16:49:02.433 E/ActivityManager( 2466): Load: 0.6 / 0.61 / 0.42
翻译：5分钟，10分钟，15分钟内的平均负载分别为：0.6 , 0.61 , 0.42

在这里我们大概知道问题是什么了，结合我们之前的操作流程，我们知道问题是在点击按钮某时候可能处理不过来按钮事件，导致超时无响应。那么现在似乎已经可以进行工作了。我们知道Activity中是通过重载dispatchTouchEvent(MotionEvent ev)来处理点击屏幕事件。然后我们可以顺藤摸瓜，一点点分析去查找原因。但这样够了么？
其实不够，至少我们不能准确的知道到底问题在哪儿，只是猜测，比如这个应用程序中，我就在顺藤摸瓜的时候发现了多个IO操作的地方都在主线程中，可能引起问题，但不好判断到底是哪个，所以我们目前掌握的信息还不够。

于是我们再分析虚拟机信息，搜索“Dalvik Thread”关键词，快速定位到本应用程序的虚拟机信息日志，如下：
----- pid 2922 at 2011-01-13 13:51:07 -----
Cmd line: com.android.mms

DALVIK THREADS:
"main" prio=5 tid=1 NATIVE
| group="main" sCount=1 dsCount=0 s=N obj=0x4001d8d0 self=0xccc8
| sysTid=2922 nice=0 sched=0/0 cgrp=default handle=-1345017808
| schedstat=( 3497492306 15312897923 10358 )
at android.media.MediaPlayer._release(Native Method)
at android.media.MediaPlayer.release(MediaPlayer.java:1206)
at android.widget.VideoView.stopPlayback(VideoView.java:196)
at com.android.mms.ui.SlideView.stopVideo(SlideView.java:640)
at com.android.mms.ui.SlideshowPresenter.presentVideo(SlideshowPresenter.java:443)
at com.android.mms.ui.SlideshowPresenter.presentRegionMedia(SlideshowPresenter.java:219)
at com.android.mms.ui.SlideshowPresenter$4.run(SlideshowPresenter.java:516)
at android.os.Handler.handleCallback(Handler.java:587)
at android.os.Handler.dispatchMessage(Handler.java:92)
at android.os.Looper.loop(Looper.java:123)
at android.app.ActivityThread.main(ActivityThread.java:4627)
at java.lang.reflect.Method.invokeNative(Native Method)
at java.lang.reflect.Method.invoke(Method.java:521)
at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:858)
at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:616)
at dalvik.system.NativeStart.main(Native Method)

"Binder Thread #3" prio=5 tid=11 NATIVE
| group="main" sCount=1 dsCount=0 s=N obj=0x4837f808 self=0x242280
| sysTid=3239 nice=0 sched=0/0 cgrp=default handle=2341032
| schedstat=( 32410506 932842514 164 )
at dalvik.system.NativeStart.run(Native Method)

"AsyncQueryWorker" prio=5 tid=9 WAIT
| group="main" sCount=1 dsCount=0 s=N obj=0x482f4b80 self=0x253e10
| sysTid=3236 nice=0 sched=0/0 cgrp=default handle=2432120
| schedstat=( 3225061 26561350 27 )
at java.lang.Object.wait(Native Method)
- waiting on <0x482f4da8> (a android.os.MessageQueue)
at java.lang.Object.wait(Object.java:288)
at android.os.MessageQueue.next(MessageQueue.java:146)
at android.os.Looper.loop(Looper.java:110)
at android.os.HandlerThread.run(HandlerThread.java:60)

"Thread-9" prio=5 tid=8 WAIT
| group="main" sCount=1 dsCount=0 s=N obj=0x4836e2b0 self=0x25af70
| sysTid=2929 nice=0 sched=0/0 cgrp=default handle=2370896
| schedstat=( 130248 4389035 2 )
at java.lang.Object.wait(Native Method)
- waiting on <0x4836e240> (a java.util.ArrayList)
at java.lang.Object.wait(Object.java:288)
at com.android.mms.data.Contact$ContactsCache$TaskStack$1.run(Contact.java:488)
at java.lang.Thread.run(Thread.java:1096)

"Binder Thread #2" prio=5 tid=7 NATIVE
| group="main" sCount=1 dsCount=0 s=N obj=0x482f8ca0 self=0x130fd0
| sysTid=2928 nice=0 sched=0/0 cgrp=default handle=1215968
| schedstat=( 40610049 1837703846 195 )
at dalvik.system.NativeStart.run(Native Method)

"Binder Thread #1" prio=5 tid=6 NATIVE
| group="main" sCount=1 dsCount=0 s=N obj=0x482f4a78 self=0x128a50
| sysTid=2927 nice=0 sched=0/0 cgrp=default handle=1201352
| schedstat=( 40928066 928867585 190 )
at dalvik.system.NativeStart.run(Native Method)

"Compiler" daemon prio=5 tid=5 VMWAIT
| group="system" sCount=1 dsCount=0 s=N obj=0x482f1348 self=0x118960
| sysTid=2926 nice=0 sched=0/0 cgrp=default handle=1149216
| schedstat=( 753021350 3774113668 6686 )
at dalvik.system.NativeStart.run(Native Method)

"JDWP" daemon prio=5 tid=4 VMWAIT
| group="system" sCount=1 dsCount=0 s=N obj=0x482f12a0 self=0x132940
| sysTid=2925 nice=0 sched=0/0 cgrp=default handle=1255680
| schedstat=( 2827103 29553323 19 )
at dalvik.system.NativeStart.run(Native Method)

"Signal Catcher" daemon prio=5 tid=3 RUNNABLE
| group="system" sCount=0 dsCount=0 s=N obj=0x482f11e8 self=0x135988
| sysTid=2924 nice=0 sched=0/0 cgrp=default handle=1173688
| schedstat=( 11793815 12456169 7 )
at dalvik.system.NativeStart.run(Native Method)

"HeapWorker" daemon prio=5 tid=2 VMWAIT
| group="system" sCount=1 dsCount=0 s=N obj=0x45496028 self=0x135848
| sysTid=2923 nice=0 sched=0/0 cgrp=default handle=1222608
| schedstat=( 79049792 1520840200 95 )
at dalvik.system.NativeStart.run(Native Method)

----- end 2922 -----

每一段都是一个线程，当然我们还是看线程号为1的主线程了。通过分析发现关键问题是这样：
at com.android.mms.ui.SlideshowPresenter$3.run(SlideshowPresenter.java:531)
定位到代码：
mHandler.post(new Runnable() {
public void run() {
try {
presentRegionMedia(view, (RegionMediaModel) model, dataChanged);
} catch (OMADRMException e) {
Log.e(TAG, e.getMessage(), e);
Toast.makeText(mContext,
mContext.getString(R.string.insufficient_drm_rights),
Toast.LENGTH_SHORT).show();
} catch (IOException e){
Log.e(TAG, e.getMessage(), e);
Toast.makeText(mContext,
mContext.getString(R.string.insufficient_drm_rights),
Toast.LENGTH_SHORT).show();

}
}

很清楚了， Handler.post 方法之后执行时间太长的问题。继续看presentRegionMedia(view, (RegionMediaModel) model, dataChanged);方法，发现最终是调用的framework 中MediaPlayer.stop方法。
至此，我们的日志分析算是告一段落。可以开始思考解决办法了。

====================================
ANRs (“Application Not Responding”)，意思是”应用没有响应“。
在如下情况下，Android会报出ANR错误：
– 主线程 (“事件处理线程” / “UI线程”) 在5秒内没有响应输入事件
– BroadcastReceiver 没有在10秒内完成返回

通常情况下，下面这些做法会导致ANR
1、在主线程内进行网络操作
2、在主线程内进行一些缓慢的磁盘操作（例如执行没有优化过的SQL查询）

应用应该在5秒或者10秒内响应，否则用户会觉得“这个应用很垃圾”“烂”“慢”...等等

AsyncTask要点

1、必须从主线程调用，或者线程中有Handler或Looper。

2、不要在一个可能会被另外一个AsyncTask调用的库里面使用AsyncTask（AsyncTask是不可重入的）

3、如果从一个activity中调用，activity进程可能会在AsyncTask结束前退出，例如：

用户退出了activity
系统内存不足
系统暂存了activity的状态留待后用
系统干掉了你的线程
如果AsyncTask中的工作很重要，应该使用......

IntentService 的好处

Acitivity的进程，当处理Intent的时候，会产生一个对应的Service
Android的进程处理器现在会尽可能的不kill掉你
非常容易使用

其它技巧

1、当启动AsyncTask的时候，立刻disable UI元素（按钮等等）。

2、显示一些动画，表示在处理中

3、使用进度条对话框

4、使用一个定时器作为耗时警告，在AsyncTask开始时启动定时器，在AsyncTask的onPostExecute方法中取消定时器。

5、当不确定要耗时多久的时候，组合使用上述所有方法

总结

离开主线程！
磁盘和网络操作不是马上就能完的
了解sqlite在干嘛
进度展示很好
================================================
Android中对付ANR的N种武器
以前做Android系统开发，一般很少写程序。现在到一公司做Android互联网应用，程序中不时出现一些ANR。
上峰对ANR非常的关注，期望我能彻底解决该项目的ANR。⊙﹏⊙b汗！
因此我对ANR进行了些思考，并和刚从腾讯QQ项目组跳槽来公司北京总部的某架构师同事进行了探讨。他也基本认同我的观点。
现将我应对ANR的思路整理如下：
一、在项目之前，应该确保工程师理解产生ANR的基本原理，Handler的基本原理，明白一些主要回调函数的执行线程。如果工程师还没达到这些要求，应该通过培训等方式尽量让工程师了解这些知识。
关于这些技术的知识可参考《关于ANR的官方建议》和《Android线程模型》和《Looper和Handler》
二、如果程序在初始化阶段较耗时，考虑显示一splash屏或者尽快让主视图快速显示处理，然后才显示其他的视图。不管是哪一种情况，应该设法表明程序正在往前执行，以免用户觉得应用冻结了。
三、在进行架构设计时，架构师应该尽量采用MVC架构，另外一定要清楚那些代码应该是在主线程中执行，那些代码应该是在非主线程中执行。当然要做好框架也不容易啊！⊙﹏⊙b汗！
四、对于已处于项目中后期，而没有采用MVC框架，或者采用了MVC框架但其实现并不太好的项目，应该画出其整体框架图，时序图等进行分析，尽量采用较小的代价，逐步迭代的方式让其项目最后达到良好的MVC架构。对于我们的当前项目，我正试图使用该方式来最大程度的避免ANR。也不知道最后能不能达到很好的效果。
五、在进行编码时，工程师一定要考虑当前代码死否在主线程中执行；当前代码是否是耗时操作;
线程对锁的竞争是否可能造成代码的等待，而耗时太多；代码是否可能造成死锁，而产生ANR。
六、如果应用程序中使用了第三方的应用程序，请把这些第三方的应用程序做为单独的进程来处理，以避免它的不良代码而造成本项目出现ANR。关于此技术请参考《Android中单APK应用多进程》
七、在程序运行时，出现了ANR，工程师应该通过/data/anr/traces.txt并结合代码，进行ANR的分析。
八、在项目中后期，你可以使用 StrictMode 来帮助你在主线程中查找潜在的耗时操作，比如对网络或数据库操作。
九、在项目后期，应该通过monkey等来进行压力测试，找出潜在的ANR，并进行修改。
关于monkey的使用请参考《Android的monkey用法》
十、对于一些重要的ANR及不良代码，要进行归纳和总结，形成文档，以便分享给其他的同事或项目组，并作为新员工的培训资料。
总结
每当产生ANR我们可以根据/data/anr/traces.txt分析解决，但这个顽疾很难从根本上解决，只有通过引入好的框架（比如MVC框架），提升开发工程师认知，技术积累去避免。

结束！
=========================================
Android通过ANR来查看死锁
来自 Fgamers 2011年 4月 25日
3,857 次阅读评论（0）
死锁很难改。但是我们可以ANR来得到traces.txt。在traces.txt中可以查看那些线程在wait，当然死锁的线程也在其中。这样对查找死锁大大提供了方便。
注意：方式ANR后，在手机中就会生成如下文件data\anr\traces.txt
下面直接给出实例。
文件1：DeadLockTraceActivity.java

package com.gameloft.robin;
import android.app.Activity;
import android.os.Bundle;
import android.os.Handler;
public class DeadLockTraceActivity extends Activity {
public void onCreate(Bundle savedInstanceState) {
super.onCreate(savedInstanceState);
setContentView(R.layout.deadlock_trace);
}
String tag="robin";
public void onResume()
{
super.onResume();
new ThreadDeadLockExample().start();
Handler handler=new Handler();
Runnable run=new Runnable(){public void run(){forceWait();}};
handler.post(run);
}
synchronized void forceWait()
{
try {
wait(60000);
} catch (InterruptedException e) {
// TODO Auto-generated catch block
e.printStackTrace();
}
}
}
文件2：ThreadDeadLockExample.java

package com.gameloft.robin;
import java.util.concurrent.locks.ReentrantLock;
import android.util.Log;
public class ThreadDeadLockExample{
private final ReentrantLock lockA = new ReentrantLock(true);
private final ReentrantLock lockB = new ReentrantLock(true);
String tag="robin";
void start()
{
Log.i(tag, "ThreadDeadLockExample start");
new ThreadA("ThreadA").start();
new ThreadB("ThreadB").start();
}
class ThreadA extends Thread
{
ThreadA(String name)
{
super(name);
}
public void run()
{
Log.i(tag, "try to lock A"+" in ThreadA");
lockA.lock();
try {
Thread.sleep(1000);
} catch (InterruptedException e) {
// TODO Auto-generated catch block
e.printStackTrace();
}
Log.i(tag, "lock A successful"+" in ThreadA");
Log.i(tag, "try to lock B"+" in ThreadA");
lockB.lock();
Log.i(tag, "lock B successful"+" in ThreadA");
lockB.unlock();
Log.i(tag, "unlock B"+" in ThreadA");
lockA.unlock();
Log.i(tag, "unlock A"+" in ThreadA");
}
}
class ThreadB extends Thread
{
ThreadB(String name)
{
super(name);
}
public void run()
{
Log.i(tag, "try to lock B "+" in ThreadB");
lockB.lock();
try {
Thread.sleep(1000);
} catch (InterruptedException e) {
// TODO Auto-generated catch block
e.printStackTrace();
}
Log.i(tag, "lock B successful"+" in ThreadB");
Log.i(tag, "try to lock A"+" in ThreadB");
lockA.lock();
Log.i(tag, "lock A successful"+" in ThreadB");
lockA.unlock();
Log.i(tag, "unlock A"+" in ThreadB");
lockB.unlock();
Log.i(tag, "unlock B"+" in ThreadB");
}
}
}
traces.txt 文件摘要：

DALVIK THREADS:
"main" prio=5 tid=1 TIMED_WAIT
| group="main" sCount=1 dsCount=0 s=N obj=0x400208b8 self=0xcdf0
| sysTid=1732 nice=0 sched=0/0 cgrp=unknown handle=-1345026000
at java.lang.Object.wait(Native Method)
- waiting on <0x4a5ba4b0> (a com.gameloft.robin.DeadLockTraceActivity)
at java.lang.Object.wait(Object.java:326)
at com.gameloft.robin.DeadLockTraceActivity.forceWait(DeadLockTraceActivity.java:24)
at com.gameloft.robin.DeadLockTraceActivity$1.run(DeadLockTraceActivity.java:18)
at android.os.Handler.handleCallback(Handler.java:587)
at android.os.Handler.dispatchMessage(Handler.java:92)
at android.os.Looper.loop(Looper.java:123)
at android.app.ActivityThread.main(ActivityThread.java:4633)
at java.lang.reflect.Method.invokeNative(Native Method)
at java.lang.reflect.Method.invoke(Method.java:521)
at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:858)
at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:616)
at dalvik.system.NativeStart.main(Native Method)

"ThreadB" prio=5 tid=10 WAIT
| group="main" sCount=1 dsCount=0 s=N obj=0x4a5bf868 self=0x2174f8
| sysTid=1741 nice=0 sched=0/0 cgrp=unknown handle=2192952
at java.lang.Object.wait(Native Method)
- waiting on <0x4a5bf980> (a java.lang.VMThread)
at java.lang.Thread.parkFor(Thread.java:1535)
at java.lang.LangAccessImpl.parkFor(LangAccessImpl.java:48)
at sun.misc.Unsafe.park(Unsafe.java:317)
at java.util.concurrent.locks.LockSupport.park(LockSupport.java:131)
at java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:790)
at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireQueued(AbstractQueuedSynchronizer.java:823)
at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(AbstractQueuedSynchronizer.java:1153)
at java.util.concurrent.locks.ReentrantLock$FairSync.lock(ReentrantLock.java:200)
at java.util.concurrent.locks.ReentrantLock.lock(ReentrantLock.java:261)
at com.gameloft.robin.ThreadDeadLockExample$ThreadB.run(ThreadDeadLockExample.java:61)

"ThreadA" prio=5 tid=9 WAIT
| group="main" sCount=1 dsCount=0 s=N obj=0x4a5bf438 self=0x216858
| sysTid=1740 nice=0 sched=0/0 cgrp=unknown handle=2189720
at java.lang.Object.wait(Native Method)
- waiting on <0x4a5bf590> (a java.lang.VMThread)
at java.lang.Thread.parkFor(Thread.java:1535)
at java.lang.LangAccessImpl.parkFor(LangAccessImpl.java:48)
at sun.misc.Unsafe.park(Unsafe.java:317)
at java.util.concurrent.locks.LockSupport.park(LockSupport.java:131)
at java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:790)
at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireQueued(AbstractQueuedSynchronizer.java:823)
at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(AbstractQueuedSynchronizer.java:1153)
at java.util.concurrent.locks.ReentrantLock$FairSync.lock(ReentrantLock.java:200)
at java.util.concurrent.locks.ReentrantLock.lock(ReentrantLock.java:261)
at com.gameloft.robin.ThreadDeadLockExample$ThreadA.run(ThreadDeadLockExample.java:35)
原文链接：http://hubingforever.blog.163.com/blog/static/17104057920112253531415/
===========================================
粗略的来分会有两种情况导致ANR：

第一类：dispatchTimeout 输入事件分发超时，一般是由于主线程在5秒之内没有响应输入事件。

第二类：BroadcastReceiver没有在系统设定的时间内完成并返回。

再细分的话ANR可能是由主线程导致也可能是由非主线程导致：
由于主线程导致的情况：

1.耗时网络访问

2.当有大量数据读写操作时再请求数据读写
3.数据库操作(比如其他大数据量应用访问数据库导致数据库负载过重时)

4.硬件操作(比如Camera)

5.调用thread_join() / Sleep() / Wait() 或者等待locker的时候

6.Service binder数量达到上限

7.在system_server中发生WatchDog ANR

8.Service忙导致超时无响应

由于非主线程导致的情况：

1.非主线程持有lock，导致主线程等待lock超时

2.非主线程终止或者崩溃导致主线程一直等待

本文原创，请勿用于商业用途。转载请注明出处：http://www.cnblogs.com/mobile-veterans
=============================================================
一：什么是ANR
ANR:Application Not Responding，即应用无响应
二：ANR的类型
ANR一般有三种类型：
1：KeyDispatchTimeout(5 seconds) --主要类型
按键或触摸事件在特定时间内无响应
2：BroadcastTimeout(10 seconds)
BroadcastReceiver在特定时间内无法处理完成
3：ServiceTimeout(20 seconds) --小概率类型
Service在特定的时间内无法处理完成
三：KeyDispatchTimeout
Akey or touch event was not dispatched within the specified time（按键或触摸事件在特定时间内无响应）
具体的超时时间的定义在framework下的
ActivityManagerService.java
//How long we wait until we timeout on key dispatching.
staticfinal int KEY_DISPATCHING_TIMEOUT = 5*1000
四：为什么会超时呢？
超时时间的计数一般是从按键分发给app开始。超时的原因一般有两种：
(1)当前的事件没有机会得到处理（即UI线程正在处理前一个事件，没有及时的完成或者looper被某种原因阻塞住了）
(2)当前的事件正在处理，但没有及时完成
五：如何避免KeyDispatchTimeout
1：UI线程尽量只做跟UI相关的工作
2：耗时的工作（比如数据库操作，I/O，连接网络或者别的有可能阻碍UI线程的操作）把它放入单独的线程处理
3：尽量用Handler来处理UIthread和别的thread之间的交互

六：UI线程
说了那么多的UI线程，那么哪些属于UI线程呢？
UI线程主要包括如下：
Activity:onCreate(), onResume(), onDestroy(), onKeyDown(), onClick(),etc
AsyncTask: onPreExecute(), onProgressUpdate(), onPostExecute(), onCancel,etc
Mainthread handler: handleMessage(), post*(runnable r), etc
other
七:如何去分析ANR
先看个LOG:
04-01 13:12:11.572 I/InputDispatcher( 220): Application is not responding:Window{2b263310com.android.email/com.android.email.activity.SplitScreenActivitypaused=false}. 5009.8ms since event, 5009.5ms since waitstarted
04-0113:12:11.572 I/WindowManager( 220): Input event dispatching timedout sending tocom.android.email/com.android.email.activity.SplitScreenActivity
04-01 13:12:14.123 I/Process( 220): Sending signal. PID: 21404 SIG: 3---发生ANR的时间和生成trace.txt的时间
04-01 13:12:14.123 I/dalvikvm(21404):threadid=4: reacting to signal 3
……
04-0113:12:15.872 E/ActivityManager( 220): ANR in com.android.email(com.android.email/.activity.SplitScreenActivity)
04-0113:12:15.872 E/ActivityManager( 220): Reason:keyDispatchingTimedOut
04-0113:12:15.872 E/ActivityManager( 220): Load: 8.68 / 8.37 / 8.53
04-0113:12:15.872 E/ActivityManager( 220):CPUusage from 4361ms to 699ms ago----CPU在ANR发生前的使用情况

04-0113:12:15.872 E/ActivityManager( 220): 5.5%21404/com.android.email: 1.3% user + 4.1% kernel / faults: 10 minor
04-0113:12:15.872 E/ActivityManager( 220): 4.3%220/system_server: 2.7% user + 1.5% kernel / faults: 11 minor 2 major
04-0113:12:15.872 E/ActivityManager( 220): 0.9%52/spi_qsd.0: 0% user + 0.9% kernel
04-0113:12:15.872 E/ActivityManager( 220): 0.5%65/irq/170-cyttsp-: 0% user + 0.5% kernel
04-0113:12:15.872 E/ActivityManager( 220): 0.5%296/com.android.systemui: 0.5% user + 0% kernel
04-0113:12:15.872 E/ActivityManager( 220): 100%TOTAL: 4.8% user + 7.6% kernel + 87% iowait
04-0113:12:15.872 E/ActivityManager( 220):CPUusage from 3697ms to 4223ms later:-- ANR后CPU的使用量
04-0113:12:15.872 E/ActivityManager( 220): 25%21404/com.android.email: 25% user + 0% kernel / faults: 191 minor
04-0113:12:15.872 E/ActivityManager( 220): 16% 21603/__eas(par.hakan: 16% user + 0% kernel
04-0113:12:15.872 E/ActivityManager( 220): 7.2% 21406/GC: 7.2% user + 0% kernel
04-0113:12:15.872 E/ActivityManager( 220): 1.8% 21409/Compiler: 1.8% user + 0% kernel
04-0113:12:15.872 E/ActivityManager( 220): 5.5%220/system_server: 0% user + 5.5% kernel / faults: 1 minor
04-0113:12:15.872 E/ActivityManager( 220): 5.5% 263/InputDispatcher: 0% user + 5.5% kernel
04-0113:12:15.872 E/ActivityManager( 220): 32%TOTAL: 28% user + 3.7% kernel

从LOG可以看出ANR的类型，CPU的使用情况，如果CPU使用量接近100%，说明当前设备很忙，有可能是CPU饥饿导致了ANR
如果CPU使用量很少，说明主线程被BLOCK了
如果IOwait很高，说明ANR有可能是主线程在进行I/O操作造成的
除了看LOG，解决ANR还得需要trace.txt文件，----pid 21404 at 2011-04-0113:12:14 -----
Cmdline: com.android.email

DALVIK THREADS:
(mutexes: tll=0tsl=0 tscl=0 ghl=0 hwl=0 hwll=0)
"main" prio=5 tid=1NATIVE
| group="main" sCount=1 dsCount=0obj=0x2aad2248 self=0xcf70
| sysTid=21404 nice=0 sched=0/0cgrp=[fopen-error:2] handle=1876218976
atandroid.os.MessageQueue.nativePollOnce(Native Method)
atandroid.os.MessageQueue.next(MessageQueue.java:119)
atandroid.os.Looper.loop(Looper.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)
说明主线程在等待下条消息进入消息队列
八：Thread状态
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_SUSPENDED = 9, /* suspended, usually by GC or debugger */

九：如何调查并解决ANR
1：首先分析log
2: 从trace.txt文件查看调用stack.
3: 看代码
4：仔细查看ANR的成因（iowait?block?memoryleak?）
案例1：关键词:ContentResolver in AsyncTask onPostExecute, high iowait
Process:com.android.email
Activity:com.android.email/.activity.MessageView
Subject:keyDispatchingTimedOut
CPU usage from 2550ms to -2814ms ago:
5%187/system_server: 3.5% user + 1.4% kernel / faults: 86 minor 20major
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 2010-12-17 17:46:51 -----
Cmd line:com.android.email

DALVIK 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=1876218976
at 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.<init>(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
原因：IOWait很高，说明当前系统在忙于I/O，因此数据库操作被阻塞
原来：
finalMessagemessage=Message.restoreMessageWithId(mProviderContext,messageId);
if(message==null){
return;
}

Accountaccount=Account.restoreAccountWithId(mProviderContext,message.mAccountKey);

if(account==null){
return;//isMessagingController returns false for null, but let's make itclear.
}

if(isMessagingController(account)){
new Thread(){
@Override
public void run(){
mLegacyController.processPendingActions(message.mAccountKey);
}
}.start();
}
解决后：
newThread() {
finalMessagemessage=Message.restoreMessageWithId(mProviderContext,messageId);

if(message==null){
return;
}

Accountaccount=Account.restoreAccountWithId(mProviderContext,message.mAccountKey);

if(account==null){
return;//isMessagingController returns false for null, but let's make itclear.
}

if(isMessagingController(account)) {
mLegacyController.processPendingActions(message.mAccountKey);
}
}.start();
关于AsyncTask:http://developer.android.com/reference/android/os/AsyncTask.html

案例2：关键词:在UI线程进行网络数据的读写
ANRin process: com.android.mediascape:PhotoViewer (last incom.android.mediascape:PhotoViewer)
Annotation:keyDispatchingTimedOut
CPU usage:
Load: 6.74 / 6.89 / 6.12
CPUusage from 8254ms to 3224ms ago:
ovider.webmedia: 4% = 4% user +0% kernel / faults: 68 minor
system_server: 2% = 1% user + 0%kernel / faults: 18 minor
re-initialized>: 0% = 0% user + 0%kernel / faults: 50 minor
events/0: 0% = 0% user + 0%kernel
TOTAL:7% = 6% user + 1% kernel

DALVIKTHREADS:
""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=-1343993184
atorg.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)
关于网络连接，在设计的时候可以设置个timeout的时间或者放入独立的线程来处理。
关于Handler的问题，可以参考：http://developer.android.com/reference/android/os/Handler.html
案例3：
关键词：Memoryleak/Thread leak
11-1621:41:42.560 I/ActivityManager( 1190): ANR in process:android.process.acore (last in android.process.acore)
11-1621:41:42.560 I/ActivityManager( 1190): Annotation:keyDispatchingTimedOut
11-16 21:41:42.560 I/ActivityManager(1190): CPU usage:
11-16 21:41:42.560 I/ActivityManager( 1190):Load: 11.5 / 11.1 / 11.09
11-16 21:41:42.560 I/ActivityManager(1190): CPU usage from 9046ms to 4018ms ago:
11-16 21:41:42.560I/ActivityManager( 1190): d.process.acore:98%= 97% user + 0% kernel / faults: 1134 minor
11-16 21:41:42.560I/ActivityManager( 1190): system_server: 0% = 0% user + 0% kernel /faults: 1 minor
11-16 21:41:42.560 I/ActivityManager( 1190): adbd:0% = 0% user + 0% kernel
11-16 21:41:42.560 I/ActivityManager(1190): logcat: 0% = 0% user + 0% kernel
11-16 21:41:42.560I/ActivityManager( 1190): TOTAL:100% = 98% user + 1% kernel
Cmdline: android.process.acore

DALVIK 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=-1344001376
atdalvik.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=15470792
at 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)
分析：
atdalvik.system.VMRuntime.trackExternalAllocation(NativeMethod)内存不足导致block在创建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
解决：如果机器的内存族，可以修改虚拟机的内存为36M或更大，不过最好是复查代码，查看哪些内存没有释放
================================================
一般在平时工作中，基本上很多代码可以在eclipse+ndk进行调试，但如果需要用到具体的硬件设备，如媒体播放设备无法模拟的情况下，只能上硬件(盒子或手机)上进行调试。此时唯一的调试手段就是logcat产生log信息进行分析问题了。

　　什么时候会有Log文件的产生 ?一般在如下几种情况会产生log文件。

　　1、程序异常退出 uncaused exception

　　2、程序强制关闭 Force Closed (简称FC)

　　3、程序无响应 Application No Response(简称ANR),一般主线程超过5秒么有处理就会ANR

　　4、手动生成

　　进入控制台输入：logcat命令即可进行输出

　　第一部分

　　1、分析工具介绍

　　a、cat /proc/meminfo 显示基本的内存信息

　　------ MEMORY INFO (/proc/meminfo) ------

　　MemTotal: 285184 kB

　　MemFree: 106360 kB

　　Buffers: 0 kB

　　Cached: 60036 kB

　　SwapCached: 0 kB

　　Active: 98160 kB

　　Inactive: 49100 kB

　　Active(anon): 87260 kB

　　Inactive(anon): 288 kB

　　Active(file): 10900 kB

　　Inactive(file): 48812 kB

　　Unevictable: 0 kB

　　Mlocked: 0 kB

　　SwapTotal: 0 kB

　　SwapFree: 0 kB

　　Dirty: 0 kB

　　Writeback: 0 kB

　　AnonPages: 87240 kB

　　Mapped: 26500 kB

　　Shmem: 324 kB

　　Slab: 13340 kB

　　SReclaimable: 1672 kB

　　SUnreclaim: 11668 kB

　　KernelStack: 2160 kB

　　PageTables: 5600 kB

　　NFS_Unstable: 0 kB

　　Bounce: 0 kB

　　WritebackTmp: 0 kB

　　CommitLimit: 142592 kB

　　Committed_AS: 1065600 kB

　　VmallocTotal: 417792 kB

　　VmallocUsed: 137700 kB

　　VmallocChunk: 254980 kB

　　重点关注这下面几个值：

　　MemTotal: 285184 kB //总计物理内存的大小

　　MemFree: 106360 kB //可用内存有多少

　　Buffers: 0 kB //磁盘缓存内存的大小

　　Cached: 60036 kB

　　# free

　　free

　　total used free shared buffers

　　Mem: 285184 178884 106300 0 0

　　Swap: 0 0 0

　　Total: 285184 178884 106300

　　在linux中有这么一种思想，内存不用白不用，因此它尽可能的cache和buffer一些数据，以方便下次使用。

　　但实际上这些内存也是可以立刻拿来使用的。

　　所以空闲内存=free+buffers+cached=total-used

　　还有几个命令可使用：

　　/proc/meminfo 机器的内存使用信息

　　/proc/pid/maps pid为进程号，显示当前进程所占用的虚拟地址。

　　/proc/pid/statm 进程所占用的内存

　　b、查看进程信息

　　------ CPU INFO (top -n 1 -d 1 -m 30 -t) ------

　　能够实时显示系统中各个进程的资源占用状况，类似于 Windows 的任务管理器

　　c、android提供的一些操作工具

　　------ PROCRANK (procrank) ------

　　------ PROCMEM (procmem) ------

　　------ SHOWMAP (showmap) ------

　　... 就不一一列举了，有兴趣的朋友可以去看看

　　这此工具的代码位于android的 /system/extras

　　d、虚拟内存的查看工具

　　------ VIRTUAL MEMORY STATS (/proc/vmstat) ------

　　------ VMALLOC INFO (/proc/vmallocinfo) ------

　　2、时间信息,也是我们主要分析的信息

　　格式如下：

　　------ SYSTEM LOG (logcat -b system -v time -d *:v) ------

　　$:logcat -b system -v time -d *:v

　　01-02 08:00:02.570 I/SystemServer( 957): Notification Manager

　　01-02 08:00:02.570 I/SystemServer( 957): Device Storage Monitor

　　01-02 08:00:02.580 I/SystemServer( 957): Location Manager

　　01-02 08:00:02.580 I/SystemServer( 957): Search Service

　　01-02 08:00:02.590 I/SystemServer( 957): DropBox Service

　　01-02 08:00:02.590 I/SystemServer( 957): Wallpaper Service

　　3、虚拟机信息,包括进程的,线程的跟踪信息,这是用来跟踪进程和线程具体点的好地方。

　　------ VM TRACES JUST NOW (/data/anr/traces.txt.bugreport: 2011-01-15 16:49:02) ------

　　------ VM TRACES AT LAST ANR (/data/anr/traces.txt: 2011-01-15 16:49:02) ------

　　格式如下：

　　----- pid 1516 at 1970-01-02 08:03:07 -----

　　Cmd line: com.ipanel.join.appstore

　　DALVIK THREADS:

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

　　"main" prio=5 tid=1 NATIVE

　　| group="main" sCount=1 dsCount=0 obj=0x4001f188 self=0xd028

　　| sysTid=1516 nice=0 sched=3/0 cgrp=[fopen-error:2] handle=-1345017744

　　第二部分

　　如何分析log信息

　　1、查找错误信息的关键字眼

　　"error" "failxx" "E/" 等的错误信息

　　将这些问题先行解决掉

　　2、动态库死机

　　查看类似的“Build fingerprint:”这些关键字

　　I/DEBUG ( 692): *** *** *** *** *** *** *** *** *** *** *** *** *** *** *** ***

　　I/DEBUG ( 692): Build fingerprint: 'generic/generic/generic:2.3.1/GRH78/eng.userdev-rd6-input.20120221.113348:eng/test-keys'

　　I/DEBUG ( 692): pid: 694, tid: 694 >>> /system/bin/mediaserver <<<

　　I/DEBUG ( 692): signal 11 (SIGSEGV), code 1 (SEGV_MAPERR), fault addr 00000input module init -->

　　010

　　对于这此信息，可以查看动态库的分析：

　　http://blog.csdn.net/andyhuabing/article/details/7074979

　　3、解决java抛异常的问题解决

　　E/UsbObserver( 957): java.lang.NullPointerException

　　E/UsbObserver( 957): at com.android.server.UsbObserver.init(UsbObserver.java:131)

　　E/UsbObserver( 957): at com.android.server.UsbObserver.<init>(UsbObserver.java:65)

　　E/UsbObserver( 957): at com.android.server.ServerThread.run(SystemServer.java:419)

　　I/SystemServer( 957): UI Mode Manager Service

　　这个直接找到java代码，分析其实现即可解决

　　4、ANR问题

　　搜索“ANR”关键词，快速定位到关键事件信息。

　　定位到关键的事件信息如下:

　　I/dalvikvm( 1014): Wrote stack traces to '/data/anr/traces.txt'

　　I/Process ( 957): Sending signal. PID: 1124 SIG: 9

　　E/ActivityManager( 957): ANR in com.ipanel.join.appstore

　　E/ActivityManager( 957): Reason: Broadcast of Intent { act=android.appwidget.action.APPWIDGET_UPDATE cmp=com.ipanel.join.appstore/.widget.SmallWidget1 (has extras) }

　　E/ActivityManager( 957): Load: 1.57 / 0.38 / 0.13

　　E/ActivityManager( 957): CPU usage from 6290ms to 0ms ago:

　　E/ActivityManager( 957): 70% 957/system_server: 1.1% user + 69% kernel / faults: 204 minor

　　E/ActivityManager( 957): 8.7% 1014/com.ipanel.join.home.jelly: 7.7% user + 0.9% kernel / faults: 899 minor

　　E/ActivityManager( 957): 0.3% 687/yaffs-bg-1: 0% user + 0.3% kernel

　　E/ActivityManager( 957): 0.3% 688/yaffs-bg-1: 0% user + 0.3% kernel

　　E/ActivityManager( 957): 0.3% 935/irkeyservice: 0% user + 0.3% kernel

　　E/ActivityManager( 957): 0% 890/galcore daemon : 0% user + 0% kernel

　　E/ActivityManager( 957): 0.1% 1076/com.ipanel.join.browser: 0.1% user + 0% kernel

　　E/ActivityManager( 957): 0.1% 1124/com.ipanel.join.appstore: 0.1% user + 0% kernel

　　E/ActivityManager( 957): 75% TOTAL: 4.7% user + 70% kernel

　　E/ActivityManager( 957): CPU usage from 622ms to 1169ms later:

　　E/ActivityManager( 957): 71% 957/system_server: 0% user + 71% kernel / faults: 2 minor

　　E/ActivityManager( 957): 67% 965/SurfaceFlinger: 0% user + 67% kernel

　　E/ActivityManager( 957): 1.9% 973/ActivityManager: 1.9% user + 0% kernel

　　E/ActivityManager( 957): 1.9% 991/CursorMove: 0% user + 1.9% kernel

　　E/ActivityManager( 957): 7.6% 1014/com.ipanel.join.home.jelly: 7.6% user + 0% kernel / faults: 31 minor

　　E/ActivityManager( 957): 5.7% 1119/Thread-13: 5.7% user + 0% kernel

　　E/ActivityManager( 957): 1.9% 1123/Thread-13: 1.9% user + 0% kernel

　　E/ActivityManager( 957): 76% TOTAL: 1.8% user + 72% kernel + 1.8% softirq

　　指定哪个java包出问题

　　E/ActivityManager( 957): ANR in com.ipanel.join.appstore

　　进程号为957发生了如下错误：com.ipanel.join.appstore 包下面 Broadcast问题

　　ANR原因：

　　E/ActivityManager( 957): Reason: Broadcast of Intent { act=android.appwidget.action.APPWIDGET_UPDATE cmp=com.ipanel.join.appstore/.widget.SmallWidget1 (has extras) }

　　这是ANR的堆栈调用文件

　　I/dalvikvm( 1014): Wrote stack traces to '/data/anr/traces.txt'

　　通过上面的log信息分析，应该是接收一个广播消息时超时了

　　我们再分析虚拟机信息，打开/data/anr/traces.txt,可有通过adb pull /data/anr/traces.txt .

　　这里每一段都是一个线程，当然我们还是看线程号为1的主线程了。通过分析发现关键问题是这样：

　　搜索“DALVIK THREADS”关键词，快速定位到本应用程序的虚拟机信息日志

　　----- pid 1516 at 1970-01-02 08:03:07 -----

　　Cmd line: com.ipanel.join.appstore

　　DALVIK THREADS:

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

　　"main" prio=5 tid=1 NATIVE

　　| group="main" sCount=1 dsCount=0 obj=0x4001f188 self=0xd028

　　| sysTid=1516 nice=0 sched=3/0 cgrp=[fopen-error:2] handle=-1345017744

　　at org.apache.harmony.luni.platform.OSNetworkSystem.connect(Native Method)

　　at dalvik.system.BlockGuard$WrappedNetworkSystem.connect(BlockGuard.java:357)

　　at org.apache.harmony.luni.net.PlainSocketImpl.connect(PlainSocketImpl.java:204)

　　at org.apache.harmony.luni.net.PlainSocketImpl.connect(PlainSocketImpl.java:437)

　　at java.net.Socket.connect(Socket.java:983)

　　at org.apache.harmony.luni.internal.net.www.protocol.http.HttpConnection.<init>(HttpConnection.java:74)

　　at org.apache.harmony.luni.internal.net.www.protocol.http.HttpConnection.<init>(HttpConnection.java:48)

　　at org.apache.harmony.luni.internal.net.www.protocol.http.HttpConnection$Address.connect(HttpConnection.java:298)

　　at org.apache.harmony.luni.internal.net.www.protocol.http.HttpConnectionPool.get(HttpConnectionPool.java:89)

　　at org.apache.harmony.luni.internal.net.www.protocol.http.HttpURLConnectionImpl.getHttpConnection(HttpURLConnectionImpl.java:285)

　　at org.apache.harmony.luni.internal.net.www.protocol.http.HttpURLConnectionImpl.makeConnection(HttpURLConnectionImpl.java:267)

　　at org.apache.harmony.luni.internal.net.www.protocol.http.HttpURLConnectionImpl.retrieveResponse(HttpURLConnectionImpl.java:1018)

　　at org.apache.harmony.luni.internal.net.www.protocol.http.HttpURLConnectionImpl.getResponseCode(HttpURLConnectionImpl.java:726)

　　at com.ipanel.join.appstore.http.DefaultHttpRequest.doGet(DefaultHttpRequest.java:35)

　　at com.ipanel.join.appstore.widget.AbsSmallWidget.requestApps(AbsSmallWidget.java:117)

　　at com.ipanel.join.appstore.widget.AbsSmallWidget.getRemoteViews(AbsSmallWidget.java:56)

　　其实从这句话：

　　at org.apache.harmony.luni.platform.OSNetworkSystem.connect(Native Method)

　　基本上确认是 socket ->connect 连接超时了，导致主线程5s内没有响应从而产生ANR错误。默认的connect连接timeout时间是75s

　　其实解决办法就是利用非阻塞方式进行连接即可。

　　从CPU占用率上也可以看出是在kernel中执行堵塞住了

　　E/ActivityManager( 957): 75% TOTAL: 4.7% user + 70% kernel

　　5、执行DexOpt错误

　　W/dalvikvm( 1803): DexOpt: --- END 'SettingsProvider.apk' --- status=0x000a, process failed

　　E/dalvikvm( 1803): Unable to extract+optimize DEX from '/system/app/SettingsProvider.apk'

　　E/SystemServer( 1803): Failure starting Input Manager Service

　　E/SystemServer( 1803): java.lang.RuntimeException: Unable to get provider com.android.providers.settings.SettingsProvider: java.lang.ClassNotFoundException: com.android.providers.settings.SettingsProvider in loader dalvik.system.PathClassLoader[/system/app/SettingsProvider.apk]

　　E/SystemServer( 1803): at android.app.ActivityThread.installProvider(ActivityThread.java:3557)

　　E/SystemServer( 1803): at android.app.ActivityThread.getProvider(ActivityThread.java:3356)

　　从上面的打印看，是在解压或优化extract+optimize DEX的apk文件时出错了

　　1、没有出现magic number错误，这个原因与原子操作无关(这是一快速的加锁和解锁的轻量级操作函数)

　　2、执行dexopt出错

　　查明是服务器硬盘没空间了，导致引导文件系统的时候没有空间进行解压而失败

　　6、系统启动后默认其妙或随机死机情况

　　出现这种错误：

　　12-01 08:11:56.027: WARN/SharedBufferStack(312): waitForCondition(LockCondition) timed out (identity=19, status=0). CPU may be pegged. trying again.

　　12-01 08:11:57.315: WARN/SharedBufferStack(312): waitForCondition(LockCondition) timed out (identity=19, status=0). CPU may be pegged. trying again.

　　12-01 08:11:59.318: WARN/SharedBufferStack(312): waitForCondition(LockCondition) timed out (identity=19, status=0). CPU may be pegged. trying again.

　　12-01 08:12:03.332: WARN/SharedBufferStack(312): waitForCondition(LockCondition) timed out (identity=19, status=0). CPU may be pegged. trying again.

　　12-01 08:12:05.329: WARN/SharedBufferStack(312): waitForCondition(LockCondition) timed out (identity=19, status=0). CPU may be pegged. trying again.

　　12-01 08:12:07.216: WARN/KeyCharacterMap(312): No keyboard for id 0

　　12-01 08:12:07.216: WARN/KeyCharacterMap(312): Using default keymap: /system/usr/keychars/qwerty.kcm.bin

　　查看内存: cat /proc/meminfo 发现空闲内存只剩下几M空间了。

　　请加大android系统的内存即可解决问题

以上内容为网络搜集内容

Android ANR 搜集相关推荐

转 android anr 分析示例,[摘]Android ANR日志分析指南之实例解析
前文<[摘]Android ANR日志分析指南>也摘抄了如何分析,接下来通过实例解析. 一.主线程被其他线程lock,导致死锁 waiting on <0x1cd570> (a ...
Android ANR
ANRs ("Application Not Responding"),意思是"应用没有响应". 1)什么引发了ANR? 在Android里,应用程序的响应性是 ...
Android 系统（135）---Android anr 分析步骤总结
Android anr 分析步骤总结前言:最近经手了比较多的anr问题,声明经手不是解决,只是从log上推断造成anr的原因,以此作为根据转交给对应的人来处理. 1. ANR简介 ANR全名Appl ...
android anr 产生的类型及原因
android anr 产生的条件 android 系统中anr的本质是主线程无法响应.而导致主线程无法响应的原因大致如下: 主线程请求网络资源,数据库访问或者io访问,这些操作都是耗时操作,主线程处 ...
Android ANR是什么？
Android ANR 前言一.ANR产生的原因二.如何尽量避免ANR? 前言 ANR:Application Not Responding,应用程序无响应一.ANR产生的原因 Android系 ...
Android anr介绍
1)什么引发了ANR? 在Android里,应用程序的响应性是由Activity Manager和WindowManager系统服务监视的.当它监测到以下情况中的一个时,Android就会针对特定的应 ...
Android ANR是什么
很多初入Android 开发的网友可能发现ANR的字样,到底Android ANR是什么呢? 其实ANR就是Application Not Responding的全称,当某个应用处于长期假死状态时An ...
Android ANR问题总结(非原创)
<title>Android ANR问题总结(非原创) - Vane的博客 | Vane's Blog</title><!-- Web App Manifest --&g ...
看完这篇 Android ANR 分析，就可以和面试官装逼了！
点击上方"何俊林",马上关注,每天早上8:50准时推送真爱,请置顶或星标本文转载自公号玉刚说,原创作者htkeepmoving,原文链接:https://www.jianshu ...

Android ANR 搜集

Android ANR 搜集相关推荐

最新文章

热门文章