今天遇到一个系统重启问题，刚开始分析思路混乱，后面问题才渐渐清晰，在这儿总结一下。

前提

分析系统重启问题，首先我们要对android系统启动流程有一定的熟悉

大概流程为：

1. 启动BootLoader: 可以初始化硬件设备、建立内存空间映射图，从而将系统的软硬件环境带到一个合适状态，以便为最终调用操作系统内核准备好正确的环境。[我们最常用的就是关闭avb和selinux]
2. 启动LinuxKernel: 设置缓存、加载驱动等,然后启动init进程
3. init进程根据init.rc进行初始化: init.rc可以看做一个脚本,可以在里面修改文件权限、设置属性、拉起进程等,zygote、servicemanager、surfaceflinger这些系统进程就是它拉起来的
4. 启动zygote: zygote启动的时候会孵化system_server进程
5. 启动system_server: system_server会启动PMS、WMS、AMS等系统服务
6. 启动AMS: AMS启动的时候会去启动一些ui相关的进程如SystemUi、Launcher等

一、背景

测试同事在测试过程中，发现一个工厂测试应用卡死，过了一会儿系统重启了。工厂测试应用是我维护的。包名为：com.ifpdos.xxx

二、分析过程

1.第一步

问题本来是报给其他同事的，但是同事看到如下一行log认为是我的应用anr导致的

10-27 19:56:22.946707   788  8448 I am_anr  : [0,8369,com.ifpdos.xxx:float,814267975,executing service com.ifpdos.xxx/.FloatNavbarService]

但是从我的理解，应用anr一般不会导致系统重启，想要自证清白，只能认真分析log了。

2.第二步

出现anr一般有两种情况：
1、某系统服务产生ANR，对应log里面会有关键字

ActivityManager: Dumping to /data/anr/anr_xxx

2、某进程出现anr:

ActivityManager: ANR in xxx(应用包名)

接下来我们全局搜索到如下内容：可以看到是系统某个服务产生anr了

3.第三步

接下来，我们分析anr_2023-10-27-19-56-23-276文件，首先映入眼帘的就是
[因为公司保密原因，xxx代表公司的一个第三方库]

"main" prio=5 tid=1 Runnable
  | group="main" sCount=0 dsCount=0 flags=0 obj=0x7255dc28 self=0x87ec6210
  | sysTid=8369 nice=0 cgrp=default sched=0/0 handle=0xf5e11470
  | state=R schedstat=( 1123868093 2684110237 2643 ) utm=14 stm=98 core=0 HZ=100
  | stack=0xff73c000-0xff73e000 stackSize=8192KB
  | held mutexes= "mutator lock"(shared held)
  at xxx.utils.BoardTypeUtils.getBoardType(BoardTypeUtils.java:105)
  at xxx.StorageHelper.initBordType(StorageHelper.java:119)
  at xxx.StorageHelper.<init>(StorageHelper.java:111)
  at xxx.StorageHelper.getInstance(StorageHelper.java:175)
  - locked <0x082099f2> (a java.lang.Class<xxx>)
  at com.ifpdos.xxx.App.onCreate(App.java:24)
  at android.app.Instrumentation.callApplicationOnCreate(Instrumentation.java:1192)
  at android.app.ActivityThread.handleBindApplication(ActivityThread.java:6735)
  at android.app.ActivityThread.access$1300(ActivityThread.java:239)
  at android.app.ActivityThread$H.handleMessage(ActivityThread.java:1915)
  at android.os.Handler.dispatchMessage(Handler.java:106)
  at android.os.Looper.loop(Looper.java:223)
  at android.app.ActivityThread.main(ActivityThread.java:7680)
  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:952)
 

从上面的log里面，可以很明显的看到在我的应用onCreate等待一个lock。
到这里就很容易想到是死锁问题。

4.第四步

既然觉得是死锁问题，我们全局搜索“waiting to lock”关键字，会发现suprise，很多wait lock

根据我应用出现问题时间点，我们查看anr/anr_2023-10-27-19-57-19-998文件

----- pid 788 at 2023-10-27 19:57:21 -----
Cmd line: system_server
Build fingerprint: 'Droidlogic/t982_ar301/t982_ar301:11/RD2A.211001.002/eng.user2.20231025.150328:user/release-keys'
ABI: 'arm'
Build type: optimized
Zygote loaded classes=21264 post zygote classes=3587
Dumping registered class loaders

表示锁<0x07b403d3> 等待tid=148的线程释放；

全局搜一下，对应锁，结果如下：

"Binder:788_1D" prio=5 tid=148 Blocked
  | group="main" sCount=1 dsCount=0 flags=1 obj=0x8d480ab8 self=0x55005410
  | sysTid=6435 nice=-2 cgrp=default sched=0/0 handle=0x57e691c0
  | state=S schedstat=( 882900055 1221167633 3099 ) utm=37 stm=50 core=3 HZ=100
  | stack=0x57d6e000-0x57d70000 stackSize=1008KB
  | held mutexes=
  at com.android.server.wm.ActivityTaskManagerService$LocalService.getTopApp(ActivityTaskManagerService.java:7348)
  - waiting to lock <0x042f3493> (a com.android.server.wm.WindowManagerGlobalLock)
  at com.android.server.am.ActivityManagerService.getTopAppLocked(ActivityManagerService.java:17974)
  at com.android.server.am.OomAdjuster.updateOomAdjLocked(OomAdjuster.java:434)
  at com.android.server.am.OomAdjuster.updateOomAdjLocked(OomAdjuster.java:335)
  at com.android.server.am.ActivityManagerService.updateOomAdjLocked(ActivityManagerService.java:18020)
  at com.android.server.am.ActiveServices.sendServiceArgsLocked(ActiveServices.java:3235)
  at com.android.server.am.ActiveServices.bringUpServiceLocked(ActiveServices.java:2948)
  at com.android.server.am.ActiveServices.startServiceInnerLocked(ActiveServices.java:801)
  at com.android.server.am.ActiveServices.startServiceLocked(ActiveServices.java:735)
  at com.android.server.am.ActiveServices.startServiceLocked(ActiveServices.java:499)
  at com.android.server.am.ActivityManagerService.startService(ActivityManagerService.java:15056)
  - locked <0x07b403d3> (a com.android.server.am.ActivityManagerService)
  at android.app.IActivityManager$Stub.onTransact(IActivityManager.java:2476)
  at com.android.server.am.ActivityManagerService.onTransact(ActivityManagerService.java:2896)
  at android.os.Binder.execTransactInternal(Binder.java:1154)
  at android.os.Binder.execTransact(Binder.java:1123)

可以看到tid=148线程占有了这个锁，所以造成死锁。

三、死锁产生条件

1、互斥使用，即当资源被一个线程使用(占有)时，别的线程不能使用
2、不可抢占，资源请求者不能强制从资源占有者手中夺取资源，资源只能由资源占有者主动释放。
3、请求和保持，即当资源请求者在请求其他的资源的同时保持对原有资源的占有。
4、循环等待，即存在一个等待队列：P1占有P2的资源，P2占有P3的资源，P3占有P1的资源。这样就形成了一个等待环路。
当上述四个条件都成立的时候，便形成死锁。当然，死锁的情况下如果打破上述任何一个条件，便可解决死锁
【后面因为涉及公司代码，就不说明解决方法了】

四、系统为什么重启呢？

10-27 20:07:32.153853   306   306 E Zygote  : Zygote failed to write to system_server FD: Connection refused
10-27 20:07:32.154039   306   306 I Zygote  : Process 788 exited due to signal 9 (Killed)
10-27 20:07:32.154151   306   306 E Zygote  : Exit zygote because system server (pid 788) has terminated
10-27 20:07:32.156474   364   555 W AudioFlinger: power manager service died !!!

我们继续搜索log,发现是system server被kill掉了，为什么会被kill呢？

10-27 20:07:30.766   788   813 W Watchdog: main annotated stack trace:
10-27 20:07:30.789   788   813 W Watchdog:     at com.android.server.AlarmManagerService$DeliveryTracker.alarmComplete(AlarmManagerService.java:4697)
10-27 20:07:30.846  1687  2977 D PackageManager: getCustomerIcon: com.android.phasebeam
10-27 20:07:30.846  1687  2765 D PackageManager: getCustomerIcon: com.android.phasebeam
10-27 20:07:30.847  1687  2975 D PackageManager: getCustomerIcon: com.android.phasebeam
10-27 20:07:30.914   788   813 W Watchdog:     - waiting to lock <0x0d33ff02> (a java.lang.Object)
10-27 20:07:30.915   788   813 W Watchdog:     at com.android.server.AlarmManagerService$3.lambda$doAlarm$0$AlarmManagerService$3(AlarmManagerService.java:1555)
10-27 20:07:30.915   788   813 W Watchdog:     at com.android.server.-$$Lambda$AlarmManagerService$3$jIkPWjqS66vG6aFVQoHxR2w4HPE.run(Unknown Source:4)
10-27 20:07:30.916   788   813 W Watchdog:     at android.os.Handler.handleCallback(Handler.java:938)
10-27 20:07:30.916   788   813 W Watchdog:     at android.os.Handler.dispatchMessage(Handler.java:99)
10-27 20:07:30.916   788   813 W Watchdog:     at android.os.Looper.loop(Looper.java:223)
10-27 20:07:30.916   788   813 W Watchdog:     at com.android.server.SystemServer.run(SystemServer.java:635)
10-27 20:07:30.916   788   813 W Watchdog:     at com.android.server.SystemServer.main(SystemServer.java:419)
10-27 20:07:30.916   788   813 W Watchdog:     at java.lang.reflect.Method.invoke(Native Method)
10-27 20:07:30.916   788   813 W Watchdog:     at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:592)
10-27 20:07:30.916   788   813 W Watchdog:     at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:930)
10-27 20:07:30.926   788   813 W Watchdog: *** GOODBYE!

从log里面可以看到，是因为长时间没有等到锁，看门狗kill掉了SystemServer

五、总结

重启问题

1.如果发现system_server的进程号比较大,那么大概率重启过
2.可以用"Exit zygote"关键字去搜索找到system_server挂掉的时间，然后往上搜索下面的关键字找具体原因
3.搜索下"START com.android.internal.os.ZygoteInit"看重启的时间,然后往上搜索下面的关键字找具体死因:
DEBUG : native 层出现异常的时候会有堆栈的打印
crash : 奔溃信息打印
kill : 一些异常触发系统被强杀
tombstone : 虚拟机、c层的错误触发墓碑文件生成
died : 某些服务死掉