Log 在android中的地位非常重要，要是作为一个android程序员不能过分析log这关，算是android没有入门吧 。 下面我们就来说说如何处理log文件 。


什么时候会有Log文件的产生 ？
Log的产生大家都知道 ， 大家也都知道通过DDMS来看log ， 但什么时候会产生log文件呢 ？一般在如下几种情况会产生log文件 。 
1，程序异常退出 ， uncaused exception
2，程序强制关闭 ，Force Closed (简称FC)
3，程序无响应 ， Application No Response （简称ANR) ， 顺便，一般主线程超过5秒么有处理就会ANR
4，手动生成 。


拿到一个日志文件，要分成多段来看 。 log文件很长，其中包含十几个小单元信息，但不要被吓到 ，事实上他主要由三大块儿组成 。

1，系统基本信息 ，包括 内存，CPU ，进程队列 ，虚拟内存 ， 垃圾回收等信息 。
------ MEMORY INFO (/proc/meminfo) ------
------ CPU INFO (top -n 1 -d 1 -m 30 -t) ------
------ PROCRANK (procrank) ------
------ VIRTUAL MEMORY STATS (/proc/vmstat) ------
------ VMALLOC INFO (/proc/vmallocinfo) ------

格式如下：
------ MEMORY INFO (/proc/meminfo) ------
MemTotal:         347076 kB
MemFree:           56408 kB
Buffers:            7192 kB
Cached:           104064 kB
SwapCached:            0 kB
Active:           192592 kB
Inactive:          40548 kB
Active(anon):     129040 kB
Inactive(anon):     1104 kB
Active(file):      63552 kB
Inactive(file):    39444 kB
Unevictable:        7112 kB
Mlocked:               0 kB
SwapTotal:             0 kB
SwapFree:              0 kB
Dirty:                44 kB
Writeback:             0 kB
AnonPages:        129028 kB
Mapped:            73728 kB
Shmem:              1148 kB
Slab:              13072 kB
SReclaimable:       4564 kB
SUnreclaim:         8508 kB
KernelStack:        3472 kB
PageTables:        12172 kB
NFS_Unstable:          0 kB
Bounce:                0 kB
WritebackTmp:          0 kB
CommitLimit:      173536 kB
Committed_AS:    7394524 kB
VmallocTotal:     319488 kB
VmallocUsed:       90752 kB
VmallocChunk:     181252 kB


2，时间信息 ， 也是我们主要分析的信息 。
------ VMALLOC INFO (/proc/vmallocinfo) ------
------ EVENT INFO (/proc/vmallocinfo) ------

格式如下：
------ SYSTEM LOG (logcat -b system -v time -d *:v) ------
01-15 16:41:43.671 W/PackageManager( 2466): Unknown permission com.wsomacp.permission.PROVIDER in package com.android.mms
01-15 16:41:43.671 I/ActivityManager( 2466): Force stopping package com.android.mms uid=10092
01-15 16:41:43.675 I/UsageStats( 2466): Something wrong here, didn't expect com.sec.android.app.twlauncher to be paused
01-15 16:41:44.108 I/ActivityManager( 2466): Start proc com.sec.android.widgetapp.infoalarm for service com.sec.android.widgetapp.infoalarm/.engine.DataService: pid=20634 uid=10005 gids={3003, 1015, 3002}
01-15 16:41:44.175 W/ActivityManager( 2466): Activity pause timeout for HistoryRecord{48589868 com.sec.android.app.twlauncher/.Launcher}
01-15 16:41:50.864 I/KeyInputQueue( 2466): Input event
01-15 16:41:50.866 D/KeyInputQueue( 2466): screenCaptureKeyFlag setting 0
01-15 16:41:50.882 I/PowerManagerService( 2466): Ulight 0->7|0
01-15 16:41:50.882 I/PowerManagerService( 2466): Setting target 2: cur=0.0 target=70 delta=4.6666665 nominalCurrentValue=0
01-15 16:41:50.882 I/PowerManagerService( 2466): Scheduling light animator!
01-15 16:41:51.706 D/PowerManagerService( 2466): enableLightSensor true
01-15 16:41:51.929 I/KeyInputQueue( 2466): Input event
01-15 16:41:51.933 W/WindowManager( 2466): No focus window, dropping: KeyEvent{action=0 code=26 repeat=0 meta=0 scancode=26 mFlags=9}



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 21161 at 2011-01-15 16:49:01 -----
Cmd line: com.android.mms

DALVIK THREADS:
"main" prio=5 tid=1 NATIVE
  1. | group="main" sCount=1 dsCount=0 s=N obj=0x4001d8d0 self=0xccc8
  2.   | sysTid=21161 nice=0 sched=0/0 cgrp=default handle=-1345017808
  3.   | schedstat=( 4151552996 5342265329 10995 )
  4.   at android.media.MediaPlayer._reset(Native Method)
  5.   at android.media.MediaPlayer.reset(MediaPlayer.java:1218)
  6.   at android.widget.VideoView.release(VideoView.java:499)
  7.   at android.widget.VideoView.access$2100(VideoView.java:50)
  8.   at android.widget.VideoView$6.surfaceDestroyed(VideoView.java:489)
  9.   at android.view.SurfaceView.reportSurfaceDestroyed(SurfaceView.java:572)
  10.   at android.view.SurfaceView.updateWindow(SurfaceView.java:476)

    1.   at android.view.SurfaceView.onWindowVisibilityChanged(SurfaceView.java:206)
    2.   at android.view.View.dispatchDetachedFromWindow(View.java:6082)
    3.   at android.view.ViewGroup.dispatchDetachedFromWindow(ViewGroup.java:1156)
    4.   at android.view.ViewGroup.removeAllViewsInLayout(ViewGroup.java:2296)
    5.   at android.view.ViewGroup.removeAllViews(ViewGroup.java:2254)
    6.   at com.android.mms.ui.SlideView.reset(SlideView.java:687)
    7.   at com.android.mms.ui.SlideshowPresenter.presentSlide(SlideshowPresenter.java:189)
    8.   at com.android.mms.ui.SlideshowPresenter$3.run(SlideshowPresenter.java:531)
    9.   at android.os.Handler.handleCallback(Handler.java:587)
    10.   at android.os.Handler.dispatchMessage(Handler.java:92)
    11.   at android.os.Looper.loop(Looper.java:123)
    12.   at android.app.ActivityThread.main(ActivityThread.java:4627)
    13.   at java.lang.reflect.Method.invokeNative(Native Method)
    14.   at java.lang.reflect.Method.invoke(Method.java:521)
    15.   at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:858)
    16.   at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:616)
    17.   at dalvik.system.NativeStart.main(Native Method)
    复制代码 闲话少说， 我总结了观察log文件的基本步骤 。 1，如果是ANR问题 ， 则搜索“ANR”关键词 。 快速定位到关键事件信息 。
    2，如果是ForceClosed 和其它异常退出信息，则搜索"Fatal" 关键词， 快速定位到关键事件信息 。
    3，定位到关键事件信息后 ， 如果信息不够明确的，再去搜索应用程序包的虚拟机信息 ，查看具体的进程和线程跟踪的日志，来定位到代码 。 
    1.   at android.view.SurfaceView.onWindowVisibilityChanged(SurfaceView.java:206)
    2.   at android.view.View.dispatchDetachedFromWindow(View.java:6082)
    3.   at android.view.ViewGroup.dispatchDetachedFromWindow(ViewGroup.java:1156)
    4.   at android.view.ViewGroup.removeAllViewsInLayout(ViewGroup.java:2296)
    5.   at android.view.ViewGroup.removeAllViews(ViewGroup.java:2254)
    6.   at com.android.mms.ui.SlideView.reset(SlideView.java:687)
    7.   at com.android.mms.ui.SlideshowPresenter.presentSlide(SlideshowPresenter.java:189)
    8.   at com.android.mms.ui.SlideshowPresenter$3.run(SlideshowPresenter.java:531)
    9.   at android.os.Handler.handleCallback(Handler.java:587)
    10.   at android.os.Handler.dispatchMessage(Handler.java:92)
    11.   at android.os.Looper.loop(Looper.java:123)
    12.   at android.app.ActivityThread.main(ActivityThread.java:4627)
    13.   at java.lang.reflect.Method.invokeNative(Native Method)
    14.   at java.lang.reflect.Method.invoke(Method.java:521)
    15.   at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:858)
    16.   at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:616)
    17.   at dalvik.system.NativeStart.main(Native Method)
    复制代码 闲话少说， 我总结了观察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
    1.   at android.view.SurfaceView.onWindowVisibilityChanged(SurfaceView.java:206)
    2.   at android.view.View.dispatchDetachedFromWindow(View.java:6082)
    3.   at android.view.ViewGroup.dispatchDetachedFromWindow(ViewGroup.java:1156)
    4.   at android.view.ViewGroup.removeAllViewsInLayout(ViewGroup.java:2296)
    5.   at android.view.ViewGroup.removeAllViews(ViewGroup.java:2254)
    6.   at com.android.mms.ui.SlideView.reset(SlideView.java:687)
    7.   at com.android.mms.ui.SlideshowPresenter.presentSlide(SlideshowPresenter.java:189)
    8.   at com.android.mms.ui.SlideshowPresenter$3.run(SlideshowPresenter.java:531)
    9.   at android.os.Handler.handleCallback(Handler.java:587)
    10.   at android.os.Handler.dispatchMessage(Handler.java:92)
    11.   at android.os.Looper.loop(Looper.java:123)
    12.   at android.app.ActivityThread.main(ActivityThread.java:4627)
    13.   at java.lang.reflect.Method.invokeNative(Native Method)
    14.   at java.lang.reflect.Method.invoke(Method.java:521)
    15.   at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:858)
    16.   at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:616)
    17.   at dalvik.system.NativeStart.main(Native Method)
    复制代码 闲话少说， 我总结了观察log文件的基本步骤 。 1，如果是ANR问题 ， 则搜索“ANR”关键词 。 快速定位到关键事件信息 。
    2，如果是ForceClosed 和其它异常退出信息，则搜索"Fatal" 关键词， 快速定位到关键事件信息 。
    3，定位到关键事件信息后 ， 如果信息不够明确的，再去搜索应用程序包的虚拟机信息 ，查看具体的进程和线程跟踪的日志，来定位到代码 。 


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

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

    DALVIK THREADS:
    1. "main" prio=5 tid=1 NATIVE
    2.   | group="main" sCount=1 dsCount=0 s=N obj=0x4001d8d0 self=0xccc8
    3.   | sysTid=2922 nice=0 sched=0/0 cgrp=default handle=-1345017808
    4.   | schedstat=( 3497492306 15312897923 10358 )
    5.   at android.media.MediaPlayer._release(Native Method)
    6.   at android.media.MediaPlayer.release(MediaPlayer.java:1206)
    7.   at android.widget.VideoView.stopPlayback(VideoView.java:196)
    8.   at com.android.mms.ui.SlideView.stopVideo(SlideView.java:640)
    9.   at com.android.mms.ui.SlideshowPresenter.presentVideo(SlideshowPresenter.java:443)
    10.   at com.android.mms.ui.SlideshowPresenter.presentRegionMedia(SlideshowPresenter.java:219)
    11.   at com.android.mms.ui.SlideshowPresenter$4.run(SlideshowPresenter.java:516)
    12.   at android.os.Handler.handleCallback(Handler.java:587)
    13.   at android.os.Handler.dispatchMessage(Handler.java:92)
    14.   at android.os.Looper.loop(Looper.java:123)
    15.   at android.app.ActivityThread.main(ActivityThread.java:4627)
    16.   at java.lang.reflect.Method.invokeNative(Native Method)
    17.   at java.lang.reflect.Method.invoke(Method.java:521)
    18.   at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:858)
    19.   at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:616)
    20.   at dalvik.system.NativeStart.main(Native Method)
    1.   at android.view.SurfaceView.onWindowVisibilityChanged(SurfaceView.java:206)
    2.   at android.view.View.dispatchDetachedFromWindow(View.java:6082)
    3.   at android.view.ViewGroup.dispatchDetachedFromWindow(ViewGroup.java:1156)
    4.   at android.view.ViewGroup.removeAllViewsInLayout(ViewGroup.java:2296)
    5.   at android.view.ViewGroup.removeAllViews(ViewGroup.java:2254)
    6.   at com.android.mms.ui.SlideView.reset(SlideView.java:687)
    7.   at com.android.mms.ui.SlideshowPresenter.presentSlide(SlideshowPresenter.java:189)
    8.   at com.android.mms.ui.SlideshowPresenter$3.run(SlideshowPresenter.java:531)
    9.   at android.os.Handler.handleCallback(Handler.java:587)
    10.   at android.os.Handler.dispatchMessage(Handler.java:92)
    11.   at android.os.Looper.loop(Looper.java:123)
    12.   at android.app.ActivityThread.main(ActivityThread.java:4627)
    13.   at java.lang.reflect.Method.invokeNative(Native Method)
    14.   at java.lang.reflect.Method.invoke(Method.java:521)
    15.   at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:858)
    16.   at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:616)
    17.   at dalvik.system.NativeStart.main(Native Method)
    复制代码 闲话少说， 我总结了观察log文件的基本步骤 。 1，如果是ANR问题 ， 则搜索“ANR”关键词 。 快速定位到关键事件信息 。
    2，如果是ForceClosed 和其它异常退出信息，则搜索"Fatal" 关键词， 快速定位到关键事件信息 。
    3，定位到关键事件信息后 ， 如果信息不够明确的，再去搜索应用程序包的虚拟机信息 ，查看具体的进程和线程跟踪的日志，来定位到代码 。 




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

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

    19. "Thread-9" prio=5 tid=8 WAIT
    20.   | group="main" sCount=1 dsCount=0 s=N obj=0x4836e2b0 self=0x25af70
    21.   | sysTid=2929 nice=0 sched=0/0 cgrp=default handle=2370896
    22.   | schedstat=( 130248 4389035 2 )
    23.   at java.lang.Object.wait(Native Method)
    24.   - waiting on <0x4836e240> (a java.util.ArrayList)
    25.   at java.lang.Object.wait(Object.java:288)
    26.   at com.android.mms.data.Contact$ContactsCache$TaskStack$1.run(Contact.java:488)
    1.   at android.view.SurfaceView.onWindowVisibilityChanged(SurfaceView.java:206)
    2.   at android.view.View.dispatchDetachedFromWindow(View.java:6082)
    3.   at android.view.ViewGroup.dispatchDetachedFromWindow(ViewGroup.java:1156)
    4.   at android.view.ViewGroup.removeAllViewsInLayout(ViewGroup.java:2296)
    5.   at android.view.ViewGroup.removeAllViews(ViewGroup.java:2254)
    6.   at com.android.mms.ui.SlideView.reset(SlideView.java:687)
    7.   at com.android.mms.ui.SlideshowPresenter.presentSlide(SlideshowPresenter.java:189)
    8.   at com.android.mms.ui.SlideshowPresenter$3.run(SlideshowPresenter.java:531)
    9.   at android.os.Handler.handleCallback(Handler.java:587)
    10.   at android.os.Handler.dispatchMessage(Handler.java:92)
    11.   at android.os.Looper.loop(Looper.java:123)
    12.   at android.app.ActivityThread.main(ActivityThread.java:4627)
    13.   at java.lang.reflect.Method.invokeNative(Native Method)
    14.   at java.lang.reflect.Method.invoke(Method.java:521)
    15.   at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:858)
    16.   at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:616)
    17.   at dalvik.system.NativeStart.main(Native Method)
    复制代码 闲话少说， 我总结了观察log文件的基本步骤 。 1，如果是ANR问题 ， 则搜索“ANR”关键词 。 快速定位到关键事件信息 。
    2，如果是ForceClosed 和其它异常退出信息，则搜索"Fatal" 关键词， 快速定位到关键事件信息 。
    3，定位到关键事件信息后 ， 如果信息不够明确的，再去搜索应用程序包的虚拟机信息 ，查看具体的进程和线程跟踪的日志，来定位到代码 。 


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

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

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



    1.   at java.lang.Thread.run(Thread.java:1096)

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

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

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

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

    27. "Signal Catcher" daemon prio=5 tid=3 RUNNABLE
    28.   | group="system" sCount=0 dsCount=0 s=N obj=0x482f11e8 self=0x135988
    29.   | sysTid=2924 nice=0 sched=0/0 cgrp=default handle=1173688
    30.   | schedstat=( 11793815 12456169 7 )
    31.   at dalvik.system.NativeStart.run(Native Method)
    1.   at android.view.SurfaceView.onWindowVisibilityChanged(SurfaceView.java:206)
    2.   at android.view.View.dispatchDetachedFromWindow(View.java:6082)
    3.   at android.view.ViewGroup.dispatchDetachedFromWindow(ViewGroup.java:1156)
    4.   at android.view.ViewGroup.removeAllViewsInLayout(ViewGroup.java:2296)
    5.   at android.view.ViewGroup.removeAllViews(ViewGroup.java:2254)
    6.   at com.android.mms.ui.SlideView.reset(SlideView.java:687)
    7.   at com.android.mms.ui.SlideshowPresenter.presentSlide(SlideshowPresenter.java:189)
    8.   at com.android.mms.ui.SlideshowPresenter$3.run(SlideshowPresenter.java:531)
    9.   at android.os.Handler.handleCallback(Handler.java:587)
    10.   at android.os.Handler.dispatchMessage(Handler.java:92)
    11.   at android.os.Looper.loop(Looper.java:123)
    12.   at android.app.ActivityThread.main(ActivityThread.java:4627)
    13.   at java.lang.reflect.Method.invokeNative(Native Method)
    14.   at java.lang.reflect.Method.invoke(Method.java:521)
    15.   at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:858)
    16.   at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:616)
    17.   at dalvik.system.NativeStart.main(Native Method)
    复制代码 闲话少说， 我总结了观察log文件的基本步骤 。 1，如果是ANR问题 ， 则搜索“ANR”关键词 。 快速定位到关键事件信息 。
    2，如果是ForceClosed 和其它异常退出信息，则搜索"Fatal" 关键词， 快速定位到关键事件信息 。
    3，定位到关键事件信息后 ， 如果信息不够明确的，再去搜索应用程序包的虚拟机信息 ，查看具体的进程和线程跟踪的日志，来定位到代码 。 


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

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

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

    1.   at java.lang.Thread.run(Thread.java:1096)

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

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

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

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

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




    2. "HeapWorker" daemon prio=5 tid=2 VMWAIT
    3.   | group="system" sCount=1 dsCount=0 s=N obj=0x45496028 self=0x135848
    4.   | sysTid=2923 nice=0 sched=0/0 cgrp=default handle=1222608
    5.   | schedstat=( 79049792 1520840200 95 )
    6.   at dalvik.system.NativeStart.run(Native Method)
    复制代码 每一段都是一个线程 ，当然我们还是看线程号为1的主线程了。通过分析发现关键问题是这样：
      at com.android.mms.ui.SlideshowPresenter$3.run(SlideshowPresenter.java:531)
    定位到代码：
    1. mHandler.post(new Runnable() {
    2.                     public void run() {
    3.                         try {
    4.                             presentRegionMedia(view, (RegionMediaModel) model, dataChanged);
    5.                         } catch (OMADRMException e) {
    6.                             Log.e(TAG, e.getMessage(), e);
    7.                             Toast.makeText(mContext,
    8.                                     mContext.getString(R.string.insufficient_drm_rights),
    9.                                     Toast.LENGTH_SHORT).show();
    10.                         } catch (IOException e){
    11.                             Log.e(TAG, e.getMessage(), e);
    12.                             Toast.makeText(mContext,
    13.                                     mContext.getString(R.string.insufficient_drm_rights),
    14.                                     Toast.LENGTH_SHORT).show();
    1.   at android.view.SurfaceView.onWindowVisibilityChanged(SurfaceView.java:206)
    2.   at android.view.View.dispatchDetachedFromWindow(View.java:6082)
    3.   at android.view.ViewGroup.dispatchDetachedFromWindow(ViewGroup.java:1156)
    4.   at android.view.ViewGroup.removeAllViewsInLayout(ViewGroup.java:2296)
    5.   at android.view.ViewGroup.removeAllViews(ViewGroup.java:2254)
    6.   at com.android.mms.ui.SlideView.reset(SlideView.java:687)
    7.   at com.android.mms.ui.SlideshowPresenter.presentSlide(SlideshowPresenter.java:189)
    8.   at com.android.mms.ui.SlideshowPresenter$3.run(SlideshowPresenter.java:531)
    9.   at android.os.Handler.handleCallback(Handler.java:587)
    10.   at android.os.Handler.dispatchMessage(Handler.java:92)
    11.   at android.os.Looper.loop(Looper.java:123)
    12.   at android.app.ActivityThread.main(ActivityThread.java:4627)
    13.   at java.lang.reflect.Method.invokeNative(Native Method)
    14.   at java.lang.reflect.Method.invoke(Method.java:521)
    15.   at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:858)
    16.   at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:616)
    17.   at dalvik.system.NativeStart.main(Native Method)
    复制代码 闲话少说， 我总结了观察log文件的基本步骤 。 1，如果是ANR问题 ， 则搜索“ANR”关键词 。 快速定位到关键事件信息 。
    2，如果是ForceClosed 和其它异常退出信息，则搜索"Fatal" 关键词， 快速定位到关键事件信息 。
    3，定位到关键事件信息后 ， 如果信息不够明确的，再去搜索应用程序包的虚拟机信息 ，查看具体的进程和线程跟踪的日志，来定位到代码 。 


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

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

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

    1.   at java.lang.Thread.run(Thread.java:1096)

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

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

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

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

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


    2. "HeapWorker" daemon prio=5 tid=2 VMWAIT
    3.   | group="system" sCount=1 dsCount=0 s=N obj=0x45496028 self=0x135848
    4.   | sysTid=2923 nice=0 sched=0/0 cgrp=default handle=1222608
    5.   | schedstat=( 79049792 1520840200 95 )
    6.   at dalvik.system.NativeStart.run(Native Method)
    复制代码 每一段都是一个线程 ，当然我们还是看线程号为1的主线程了。通过分析发现关键问题是这样：
      at com.android.mms.ui.SlideshowPresenter$3.run(SlideshowPresenter.java:531)
    定位到代码：
    1. mHandler.post(new Runnable() {
    2.                     public void run() {
    3.                         try {
    4.                             presentRegionMedia(view, (RegionMediaModel) model, dataChanged);
    5.                         } catch (OMADRMException e) {
    6.                             Log.e(TAG, e.getMessage(), e);
    7.                             Toast.makeText(mContext,
    8.                                     mContext.getString(R.string.insufficient_drm_rights),
    9.                                     Toast.LENGTH_SHORT).show();
    10.                         } catch (IOException e){
    11.                             Log.e(TAG, e.getMessage(), e);
    12.                             Toast.makeText(mContext,
    13.                                     mContext.getString(R.string.insufficient_drm_rights),
    14.                                     Toast.LENGTH_SHORT).show();



    1.                         

    3.                         }
    4.                     }
    复制代码 很清楚了， Handler.post 方法之后执行时间太长的问题 。 继续看presentRegionMedia(view, (RegionMediaModel) model, dataChanged);方法 ， 发现最终是调用的framework 中MediaPlayer.stop方法 。
  1.   at android.view.SurfaceView.onWindowVisibilityChanged(SurfaceView.java:206)
  2.   at android.view.View.dispatchDetachedFromWindow(View.java:6082)
  3.   at android.view.ViewGroup.dispatchDetachedFromWindow(ViewGroup.java:1156)
  4.   at android.view.ViewGroup.removeAllViewsInLayout(ViewGroup.java:2296)
  5.   at android.view.ViewGroup.removeAllViews(ViewGroup.java:2254)
  6.   at com.android.mms.ui.SlideView.reset(SlideView.java:687)
  7.   at com.android.mms.ui.SlideshowPresenter.presentSlide(SlideshowPresenter.java:189)
  8.   at com.android.mms.ui.SlideshowPresenter$3.run(SlideshowPresenter.java:531)
  9.   at android.os.Handler.handleCallback(Handler.java:587)
  10.   at android.os.Handler.dispatchMessage(Handler.java:92)
  11.   at android.os.Looper.loop(Looper.java:123)
  12.   at android.app.ActivityThread.main(ActivityThread.java:4627)
  13.   at java.lang.reflect.Method.invokeNative(Native Method)
  14.   at java.lang.reflect.Method.invoke(Method.java:521)
  15.   at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:858)
  16.   at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:616)
  17.   at dalvik.system.NativeStart.main(Native Method)
复制代码 闲话少说， 我总结了观察log文件的基本步骤 。 1，如果是ANR问题 ， 则搜索“ANR”关键词 。 快速定位到关键事件信息 。
2，如果是ForceClosed 和其它异常退出信息，则搜索"Fatal" 关键词， 快速定位到关键事件信息 。
3，定位到关键事件信息后 ， 如果信息不够明确的，再去搜索应用程序包的虚拟机信息 ，查看具体的进程和线程跟踪的日志，来定位到代码 。 

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

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

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

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

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

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

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

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

  2. "HeapWorker" daemon prio=5 tid=2 VMWAIT
  3.   | group="system" sCount=1 dsCount=0 s=N obj=0x45496028 self=0x135848
  4.   | sysTid=2923 nice=0 sched=0/0 cgrp=default handle=1222608
  5.   | schedstat=( 79049792 1520840200 95 )
  6.   at dalvik.system.NativeStart.run(Native Method)
复制代码 每一段都是一个线程 ，当然我们还是看线程号为1的主线程了。通过分析发现关键问题是这样：
  at com.android.mms.ui.SlideshowPresenter$3.run(SlideshowPresenter.java:531)
定位到代码：
  1. mHandler.post(new Runnable() {
  2.                     public void run() {
  3.                         try {
  4.                             presentRegionMedia(view, (RegionMediaModel) model, dataChanged);
  5.                         } catch (OMADRMException e) {
  6.                             Log.e(TAG, e.getMessage(), e);
  7.                             Toast.makeText(mContext,
  8.                                     mContext.getString(R.string.insufficient_drm_rights),
  9.                                     Toast.LENGTH_SHORT).show();
  10.                         } catch (IOException e){
  11.                             Log.e(TAG, e.getMessage(), e);
  12.                             Toast.makeText(mContext,
  13.                                     mContext.getString(R.string.insufficient_drm_rights),
  14.                                     Toast.LENGTH_SHORT).show();
  1.                         

  3.                         }
  4.                     }
复制代码 很清楚了， Handler.post 方法之后执行时间太长的问题 。 继续看presentRegionMedia(view, (RegionMediaModel) model, dataChanged);方法 ， 发现最终是调用的framework 中MediaPlayer.stop方法 。

更多相关文章

  1. Android 针对ListActivity中ListView 点击事件和长按事件
  2. Android 如何自定义一个简单的组件和自定义的点击事件（中级)
  3. 控件事件android中自定义控件
  4. android 获取当前手机的 DHCP 信息ip,server 等
  5. Android菜鸟笔记-获取设备信息
  6. android监听按钮的点击事件
  7. Delphi XE5 android 捕获几个事件
  8. android 检测应用程序信息

随机推荐

  1. 详细分析MySQL主从复制
  2. MySQL百万级数据量分页查询方法及其优化
  3. MySQL数据库升级的一些"陷阱"
  4. 简述MySql四种事务隔离级别
  5. MySQL优化SQL语句的技巧
  6. MySQL如何优化查询速度
  7. MySQL性能优化之如何高效正确的使用索引
  8. MySQL单表恢复的步骤
  9. MySQL如何创建视图
  10. MySQL数据库连接异常汇总（值得收藏）