(1)如何查看db文件Log
(2)如何确认线程关系
(3)常见类型
(A)等锁
- 线程状态为"Blocked",通过关键字"held by"进一步确认哪个线程拿住了锁,如有死锁检查code逻辑进行解锁;
- 线程状态为"Waiting",表示当前线程需要另外一个线程来notify(),需要根据callstack结合code来做分析,以找到是另外的某个线程拿住了锁;
如果很多线程在等同一把锁,可能产生资源竞争问题,导致某些线程可能拿不到锁。
(B)Binder Server卡住
线程状态为"Native",且含有如下callstack:IPCThreadState::waitForResponse–>IPCThreadState::talkWithDriver,
表示卡在binder对端,下一步要找到对端,找到对端后,从对端thread的callstack中确认卡住的接口。
如何寻找binder对端:
- 根据binder thread的sysTid在SYS_BINDER_INFO/SWT_JBT_TRACES/kernel_log中查找binder通信对端,关键字"outgoing transaction";
- 在SYS_PROCESSES_AND_THREADS通过对端的sysTid查找process name;
(C)SurfaceFlinger卡住
SF hang Time > 40s(Service.sf.status值)出现sf hang的情况。
直接在"SYS_ANDROID_LOG"搜索"I watchdog",看是否有"surfaceflinger hang"关键字.
确认问题时间点:
SYS_ANDROID_EVENT_LOG:
01-04 12:26:05.982 780 1160 I watchdog: surfaceflinger hang.
SYS_ANDROID_LOG:
01-04 12:26:05.948 780 1160 V Watchdog: **SF hang Time **46185
01-04 12:26:05.949 780 1160 E Watchdog: **SWT happen **
(D)Native方法执行时间过长
线程状态为"Native",根据native方法找到对应模块,进一步确认该native方法为何执行时间过长,例如是否等待硬件返回或者硬件本身存在问题等。
(E)Zygote fork进程时卡住
线程状态为"Native",确认callstack中有"Process.zygoteSendArgsAndGetResult",对于Zygote fork进程时卡住的问题,一般是由于底层memory问题引起的,请检查是否有memory不足或者memory leak的问题。
(F)Dump时间过长
- 前面有ANR发生;
(a)前面有ANR发生,"ActivityManager"线程正在做dump操作,通过如 下 callstack确认:appNotResponding,dumpStackTraces。
(b)从"SYS_ANDROID_LOG"中确认是dump哪一个进程花的时间过长。
(c)搜索关键字"dumpStackTraces process"来确认ANR发生时所dump的进程。
(d)通过dump的上一个进程与下一个进程来确认时间差是否大于60s,或者所有的 dump时间加起来远远超过60s。
(e)ANR所引起的dump时间过长,需要看是否某个进程dump时间过长,并确认其原因。
- 前面有fatal JE、NE、KE等Exception发生;
- 自动化测试脚本主动call "dumpsys"去dump系统信息;
(a)通过callstack中确认是其他进程通过binder call发起AMS进行dump。
(b)自动化测试脚本一般是进程"adb"call进来的,该类SWT一般也不用关注,只会在eng/userdebug版本下,或者开启mtklog后才会发生。
注意:这种dump所导致的SWT,一般来说是系统loading过重,或者需要dump的信息确实过多所引起。终端用户不会发生这类问题,建议不用过多关注。
(4)Blocked案例分析
从db解析文件中_exp_main.txt查询如下信息:
进而进入到SWT_JBT_TRACES文件:
无论是通过Tid来查找,还是通过locked锁来定位,都可以最终定位到问题代码的部分。
这份Log的可以看到,System Server的32个binder都已经用完,且都处在Blocked状态:
"Binder:1353_1" prio=5 tid=10 Blocked
"Binder:1353_2" prio=5 tid=11 Blocked
"Binder:1353_3" prio=5 tid=53 Blocked
"Binder:1353_4" prio=5 tid=54 Blocked
"Binder:1353_5" prio=5 tid=145 Blocked
"Binder:1353_6" prio=5 tid=147 Blocked
"Binder:1353_7" prio=5 tid=148 Blocked
"Binder:1353_8" prio=5 tid=150 Blocked
"Binder:1353_9" prio=5 tid=139 Blocked
"Binder:1353_A" prio=5 tid=140 Blocked
"Binder:1353_B" prio=5 tid=121 Blocked
"Binder:1353_C" prio=5 tid=64 Blocked
"Binder:1353_D" prio=5 tid=82 Blocked
"Binder:1353_E" prio=5 tid=159 Blocked
"Binder:1353_F" prio=5 tid=161 Blocked
"Binder:1353_11" prio=5 tid=166 Blocked
"Binder:1353_12" prio=5 tid=167 Blocked
"Binder:1353_13" prio=5 tid=168 Blocked
"Binder:1353_14" prio=5 tid=170 Blocked
"Binder:1353_15" prio=5 tid=171 Blocked
"Binder:1353_16" prio=5 tid=172 Blocked
"Binder:1353_17" prio=5 tid=173 Blocked
"Binder:1353_18" prio=5 tid=174 Blocked
"Binder:1353_19" prio=5 tid=175 Blocked
"Binder:1353_1A" prio=5 tid=178 Blocked
"Binder:1353_1B" prio=5 tid=179 Blocked
"Binder:1353_1C" prio=5 tid=180 Blocked
"Binder:1353_1D" prio=5 tid=181 Blocked
"Binder:1353_1E" prio=5 tid=182 Blocked
"Binder:1353_1F" prio=5 tid=183 Blocked
"Binder:1353_20" prio=5 tid=184 Blocked