搜索

Android 系统奔溃触发WatchDog分析

程序员Android

共 9885字，需浏览 20分钟

 ·

2021-08-05 12:18

和你一起终身学习，这里是程序员Android

经典好文推荐，通过阅读本文，您将收获以下知识点:

一、前言
二、场景介绍
三、分析trace文件

一、前言

作为一个Android开发者，不管是App或者是System开发者，经常会遇到一些分析日志的场景，本文就通过一个场景介绍一下Android 系统触发Watdog重启时的分析思路。Watchdog俗称看门狗，Android如果一些系统服务发生异常,会触发Watchdog，导致系统重启。

二、场景介绍

QA报了一个系统重启的Bug，就是电视通过Hdmi连接盒子，在进入Hdmi页面时，系统奔溃了，既然是系统奔溃一般情况都是系统服务挂掉了，系统服务挂掉一遍会触发Watchdog.下面就是触发WatDog时的日志，一般查看Android Log中是否触发WatDog可以搜索Watchdog，或者GOODBYE关键字.

07-26 06:34:10.100  2112  2135 W Watchdog: *** Watchdog KILLING SYSTEM PROCESS: Blocked in handler on main thread (main)
07-26 06:34:10.105  2112  2135 W Watchdog: main annotated stack trace:
07-26 06:34:10.106  2112  2135 W Watchdog:     at com.android.server.tv.TvInputHardwareManager.getHardwareList(TvInputHardwareManager.java:250)
07-26 06:34:10.106  2112  2135 W Watchdog:     - waiting to lock <0x0c25fdf3> (a java.lang.Object)
07-26 06:34:10.107  2112  2135 W Watchdog:     at com.android.server.tv.TvInputManagerService$InputServiceConnection.onServiceConnected(TvInputManagerService.java:2419)
07-26 06:34:10.107  2112  2135 W Watchdog:     - locked <0x0c7f5ab0> (a java.lang.Object)
07-26 06:34:10.108  2112  2135 W Watchdog:     at android.app.LoadedApk$ServiceDispatcher.doConnected(LoadedApk.java:1954)
07-26 06:34:10.108  2112  2135 W Watchdog:     at android.app.LoadedApk$ServiceDispatcher$RunConnection.run(LoadedApk.java:1986)
07-26 06:34:10.109  2112  2135 W Watchdog:     at android.os.Handler.handleCallback(Handler.java:938)
07-26 06:34:10.109  2112  2135 W Watchdog:     at android.os.Handler.dispatchMessage(Handler.java:99)
07-26 06:34:10.109  2112  2135 W Watchdog:     at android.os.Looper.loop(Looper.java:223)
07-26 06:34:10.110  2112  2135 W Watchdog:     at com.android.server.SystemServer.run(SystemServer.java:669)
07-26 06:34:10.110  2112  2135 W Watchdog:     at com.android.server.SystemServer.main(SystemServer.java:413)
07-26 06:34:10.111  2112  2135 W Watchdog:     at java.lang.reflect.Method.invoke(Native Method)
07-26 06:34:10.111  2112  2135 W Watchdog:     at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:592)
07-26 06:34:10.111  2112  2135 W Watchdog:     at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:1060)
07-26 06:34:10.112  2112  2135 W Watchdog: *** GOODBYE!
07-26 06:34:10.112  2112  2135 I Process : Sending signal. PID: 2112 SIG: 9

上面TvInputHardwareManager.getHardwareList方法被调用的时候block住了，从下一行日志得知他block的原因是等待一个锁。

07-26 06:34:10.106  2112  2135 W Watchdog:     at com.android.server.tv.TvInputHardwareManager.getHardwareList(TvInputHardwareManager.java:250)
07-26 06:34:10.106  2112  2135 W Watchdog:     - waiting to lock <0x0c25fdf3> (a java.lang.Object)

代码如下

   public List<TvInputHardwareInfo> getHardwareList() {
        synchronized (mLock) {
            return Collections.unmodifiableList(mHardwareList);
        }
    }

那这个锁被谁持有呢？现在只看Android log已经无能为力了，需要分析trace文件,做过app开发的应该都经常遇到anr，遇到anr一般都需要分析trace文件, 这个trace文件在/data/anr/目录下。我们知道触发ANR，dump trace文件的场景如下:

Service Timeout:比如前台服务在20s内未执行完成
BroadcastQueue Timeout：比如前台广播在10s内未执行完成
ContentProvider Timeout：内容提供者,在publish过超时10s
InputDispatching Timeout: 输入事件分发超时5s，包括按键和触摸事件

其实还有一种情况也会生成trace文件,那就是触发Framework的Watchdog的时候。看一下Watchdog.java的run方法，符合条件时，会触发dump trace的操作。
//frameworks/base/services/core/java/com/android/server/Watchdog.java

@Override
    public void run() {
      ···
if (!fdLimitTriggered) {
                    final int waitState = evaluateCheckerCompletionLocked();
                    if (waitState == COMPLETED) {
                        // The monitors have returned; reset
                        waitedHalf = false;
                        continue;
                    } else if (waitState == WAITING) {
                        // still waiting but within their configured intervals; back off and recheck
                        continue;
                    } else if (waitState == WAITED_HALF) {
                        if (!waitedHalf) {
                            Slog.i(TAG, "WAITED_HALF");
                            // We've waited half the deadlock-detection interval.  Pull a stack
                            // trace and wait another half.
                            ArrayList<Integer> pids = new ArrayList<>(mInterestingJavaPids);
                          //dump trace文件
                            ActivityManagerService.dumpStackTraces(pids, null, null,
                                    getInterestingNativePids(), null);
                            waitedHalf = true;
                        }
                        continue;
                    }
  ···
}

触发dump trace时，日志里会有如下的日志:

07-26 06:33:59.485  2112  2135 I ActivityManager: Dumping to /data/anr/anr_2021-07-26-06-33-59-483

三、分析trace文件

"main" prio=5 tid=1 Blocked
  | group="main" sCount=1 dsCount=0 flags=1 obj=0x71684c28 self=0xe11c5410
  | sysTid=2112 nice=-2 cgrp=default sched=0/0 handle=0xe9762470
  | state=S schedstat=( 0 0 0 ) utm=377 stm=96 core=1 HZ=100
  | stack=0xff11b000-0xff11d000 stackSize=8192KB
  | held mutexes=
  at com.android.server.tv.TvInputHardwareManager.getHardwareList(TvInputHardwareManager.java:250)
  - waiting to lock <0x0c25fdf3> (a java.lang.Object) held by thread 100
  at com.android.server.tv.TvInputManagerService$InputServiceConnection.onServiceConnected(TvInputManagerService.java:2419)
  - locked <0x0c7f5ab0> (a java.lang.Object)
  at android.app.LoadedApk$ServiceDispatcher.doConnected(LoadedApk.java:1954)
  at android.app.LoadedApk$ServiceDispatcher$RunConnection.run(LoadedApk.java:1986)
  at android.os.Handler.handleCallback(Handler.java:938)
  at android.os.Handler.dispatchMessage(Handler.java:99)
  at android.os.Looper.loop(Looper.java:223)
  at com.android.server.SystemServer.run(SystemServer.java:669)
  at com.android.server.SystemServer.main(SystemServer.java:413)
  at java.lang.reflect.Method.invoke(Native method)
  at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:592)
  at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:1060)

这个堆栈我们在Android log里已经看到了,block的原因是等待0x0c25fdf3这个锁，那我们就搜一下0x0c25fdf3这个锁现在被谁持有.

"Binder:2112_6" prio=5 tid=100 Blocked
  | group="main" sCount=1 dsCount=0 flags=1 obj=0x135c0808 self=0xb9698810
  | sysTid=2491 nice=0 cgrp=default sched=0/0 handle=0xb478b1c0
  | state=S schedstat=( 0 0 0 ) utm=32 stm=10 core=1 HZ=100
  | stack=0xb4690000-0xb4692000 stackSize=1008KB
  | held mutexes=
  at com.android.server.tv.TvInputHardwareManager$TvInputHardwareImpl.release(TvInputHardwareManager.java:847)
  - waiting to lock <0x0234b2e5> (a java.lang.Object) held by thread 11
  at com.android.server.tv.TvInputHardwareManager$Connection.resetLocked(TvInputHardwareManager.java:652)
  at com.android.server.tv.TvInputHardwareManager$Connection.binderDied(TvInputHardwareManager.java:722)
  - locked <0x0c25fdf3> (a java.lang.Object)
  at android.os.IBinder$DeathRecipient.binderDied(IBinder.java:305)
  at android.os.BinderProxy.sendDeathNotice(BinderProxy.java:654)

从上面的trace发现0x0c25fdf3被Connection.binderDied这个方法持有的，而该方法被block原因是它调用了TvInputHardwareImpl.release方法，这个TvInputHardwareImpl.release方法被另外一个锁0x0234b2e5block住了，那么0x0234b2e5锁被谁持有呢？

"Binder:2112_2" prio=5 tid=11 Native
  | group="main" sCount=1 dsCount=0 flags=1 obj=0x131c03c8 self=0xe11c6210
  | sysTid=2127 nice=0 cgrp=default sched=0/0 handle=0xbd2401c0
  | state=S schedstat=( 0 0 0 ) utm=73 stm=20 core=3 HZ=100
  | stack=0xbd145000-0xbd147000 stackSize=1008KB
  | held mutexes=
  native: #00 pc 000715e4  /apex/com.android.runtime/lib/bionic/libc.so (__ioctl+8)
  native: #01 pc 0003f2a3  /apex/com.android.runtime/lib/bionic/libc.so (ioctl+30)
  native: #02 pc 0006d78f  /system/lib/libhidlbase.so (android::hardware::IPCThreadState::transact(int, unsigned int, android::hardware::Parcel const&, android::hardware::Parcel*, unsigned int)+438)
  native: #03 pc 0006a265  /system/lib/libhidlbase.so (android::hardware::BpHwBinder::transact(unsigned int, android::hardware::Parcel const&, android::hardware::Parcel*, unsigned int, std::__1::function<void (android::hardware::Parcel&)>)+36)
  native: #04 pc 0000c3f9  /system/lib/android.hardware.tv.input@1.0.so (android::hardware::tv::input::V1_0::BpHwTvInput::_hidl_closeStream(android::hardware::IInterface*, android::hardware::details::HidlInstrumentor*, int, int)+228)
  native: #05 pc 0000c7c5  /system/lib/android.hardware.tv.input@1.0.so (android::hardware::tv::input::V1_0::BpHwTvInput::closeStream(int, int)+36)
  native: #06 pc 00069801  /system/lib/libandroid_servers.so (android::JTvInputHal::removeStream(int, int)+440)
  at com.android.server.tv.TvInputHal.nativeRemoveStream(Native method)
  at com.android.server.tv.TvInputHal.removeStream(TvInputHal.java:111)
  - locked <0x08f771dc> (a java.lang.Object)
  at com.android.server.tv.TvInputHardwareManager$TvInputHardwareImpl.setSurface(TvInputHardwareManager.java:872)
  - locked <0x0234b2e5> (a java.lang.Object)
  at android.media.tv.ITvInputHardware$Stub.onTransact(ITvInputHardware.java:136)
  at android.os.Binder.execTransactInternal(Binder.java:1154)
  at android.os.Binder.execTransact(Binder.java:1123)

这个0x0234b2e5锁被TvInputHardwareImpl.setSurface方法持有了，那么他被block的原因是:android.hardware.tv.input@1.0.so中有个_hidl_closeStream方法被block住了。

  native: #04 pc 0000c3f9  /system/lib/android.hardware.tv.input@1.0.so (android::hardware::tv::input::V1_0::BpHwTvInput::_hidl_closeStream(android::hardware::IInterface*, android::hardware::details::HidlInstrumentor*, int, int)+228)

由于再往下追会涉及到公司的私有代码了，这里就不在继续往下分析了，但是上面的思路已经很清楚了，结合trace中的堆栈和源码定位问题应该不成问题。
总结
不管是普通的anr问题或者是这种触发Watchdog的重启，分析方式都类似的，就是先查看Android log，然后在分析trace文件，一步一步的往下挖掘。在上面的介绍中提到的WatDog,其实是Android Framework中一个很重要的机制，后面将出文章专门介绍一下其实现,v。

参考链接：https://juejin.cn/post/6989592850170118158

友情推荐：

Android 开发干货集锦

至此，本篇已结束。转载网络的文章，小编觉得很优秀，欢迎点击阅读原文，支持原创作者，如有侵权，恳请联系小编删除，欢迎您的建议与指正。同时期待您的关注，感谢您的阅读，谢谢！

点个在看，方便您使用时快速查找！

浏览 130
点赞
评论
收藏
分享

手机扫一扫分享

分享
举报
评论
图片
表情
推荐
VMware虚拟机中Linux系统奔溃，怎么办？
点击上方蓝色字体，关注我们一大早启动虚拟机准备开始工作，却遭遇到Linux系统崩溃，屏幕上显示以下错误提示：这段文本看起来是来自系统引导时的日志信息，提到了一些关于文件系统的问题和建议。根据这段信息，似乎 /dev/sda1 分区中的文件系统存在一些错误，建议手动运行 fsck 工具来检查和修复这些
OpenFeign的9个坑，每个都能让你的系统奔溃
苏三说技术
0
OpenFeign的9个坑，每个都能让你的系统奔溃
Python涨薪研究所
0
Android中GC的触发时机和条件
嵌入式Linux
0
Android JNI原理分析
字节流动
0
Android系统HTTPS原理及抓包问题分析
Android扫地僧
0
成年人的奔溃，是从离职不自由开始的
明天上线
0
数据分析系统
中电云（武汉）网络技术股份有限公司
0
进阶必备-Android Click事件是怎么触发的？
源码共读
0
FlymeOS魅族ANDROID系统
FlymeOS为魅族科技旗下ANDROID系统，界面清爽好看，有兴趣的朋友可以研究一下，适配其他机器
点赞
评论
收藏
分享

手机扫一扫分享

分享
举报