Andorid日志分析总结
一、Android 日志分类
Android 日志主要分为 kernel、radio、event、main 四种,相关描述如下:
1. Kernel log
包含多线程并发的信息,进程所使用的内存情况,进程访问磁盘的请求信息。kernel log 属于 Linux 内核的 log,可以通过读取/proc/kmsg
或者通过串口来抓取。adb 抓取 kernel log 的命令如下(需要有 root 权限):
adb shell cat /proc/kmsg > /sdcard kernel.log
2. radio log
抓取 Android RIL 层 log,在调试 Android 通信方面的代码时,这个 Log 非常关键。抓取命令如下:
adb logcat -b radio >/sdcard radio.log
3. main log
main log 和我们在 eclipse 里通过 DDMS 中看到的 log 是一致的。抓取命令如下:
adb logcat -b main >/sdcard main.log
4. event Log
系统级别的 event。比如垃圾回收,Activity 管理状态,系统的 watchdogs,其他底层的 Activity。event log 属于 system log,平时可以跟在 main log 之后。抓取命令如下:
adb logcat -b events -v time > /sdcard event.log
(-v time
表示在 log 中加入每条 log 打印的时间)
5. 完整 log
adb logcat -b
选项是可以复用的,因此我们抓取所有 Log 的命令就是复用了-b
选项。抓取命令如下:
adb logcat -b main -b system -b radio -b events -v time > /sdcard all.log
6. 其他日志相关类
frameworks/base/core/java/android/util/Log.java //用于记录main log
frameworks/base/core/java/android/util/Slog.java //用于记录framework log
frameworks/base/telephony/java/android/telephony/Rlog.java //用于记录radio log
frameworks/base/core/java/com/android/internal/os/RuntimeInit.java //内部记录了crash log
二、Android 日志级别与过滤
Android 输出的每一条日志都有一个标记和优先级与其关联。优先级是下面的字符,顺序是从低到高:
- V — 明细 verbose (最低优先级),开发调试中的一些详细信息,仅在开发中使用,不可在发布产品中输出,不是很常见,包含诸如方法名,变量值之类的信息
- D — 调试 debug,用于调试的信息,可以在发布产品中关闭,比较常见,开发中经常选择输出此种级别的日志,有时在 beta 版应用中出现
- I — 信息 info,该等级日志显示运行状态信息,可在产品出现问题时提供帮助,从该级别开始的日志通常包含完整意义的英语语句和调试信息,是最常见的日志级别
- W — 警告 warn,运行出现异常即将发生错误或表明已发生非致命性错误,该级别日志通常显示出执行过程中的意外情况,例如将 try-catch 语句块中的异常打印堆栈轨迹之后可输出此种级别日志
- E — 错误 error,已经出现可影响运行的错误,比如应用 crash 时输出的日志
- F — 严重错误 fatal,比 error 级别更高,目前我只在 android 系统内核发出的日志中看到此种级别。在 Android6.0 以前表明开发者认为绝对不应该出现的错误,在此以后一般开发场景下绝不应该输出此种级别的日志
- S — 无记载 silent,寂静,最高级别,没有一条日志会属于这个级别,仅仅作为关闭 logcat 输出的过滤器参数
相关过滤命令
(使用 I,V,D,E,F,W 等过滤)
# 清除缓存的log信息
adb logcat -c
# 显示所有优先级大于等于“info”的日志
adb logcat *:I
# 显示所有优先级大于等于“verbose”的日志
adb logcat *:V
# 仅输出标记为“ActivityManager”且优先级大于等于“Info”的日志
adb logcat ActivityManager:I *:S
分类展示
# 显示 papaya 的日志信息
adb logcat -s papaya
# 按照标签来打印日志信息
adb logcat -v tag
# 显示 I,D,E等日志类型的进程ID、线程ID
adb logcat -v thread
grep 过滤(windows 可用 find 代替)
# 根据进程id来过滤
adb logcat | grep PID
# 根据字符串来过滤,并忽略大小写
adb logcat | grep -i myapp
# 仅匹配 tag 过滤, tag 是一行开头的第三个字符开始
adb logcat | grep "^..MyApp"
三、Bugreport 日志分析
bugreport 记录 android 启动过程的 log,以及启动后的系统状态:包括进程列表,内存信息,VM 信息等。
- dumpstate:内存信息,CPU 信息,Procrank 信息,系统日志 VmTrack 信息等。
- build.Prop:当前版本 / 当前命令,显示系统 Build 的一些属性等。
- dumpsys:(Dump of serene Meminfo)显示某个进程的更详细的内存消耗情况及 Native and Java(Davik)堆栈的统计
dumpsys 可以用于查询以下信息,例如:dumpsys [options]
- meminfo : 显示内存信息
- cpuinfo : 显示 CPU 信息
- account : 显示 accounts 信息
- activity : 显示所有的 activities 的信息
- window : 显示键盘,窗口和它们的关系
- wifi : 显示 wifi 信息
四、Log 分析步骤
Step 1: 确认系统环境
首先查看一些版本信息,确认问题的系统环境。
Step 2: 查看 CPU/MEMORY 使用状况
看是否有内存耗尽、CPU 繁忙等情况出现。
Step 3: 分析 traces 信息
traces 是系统出错以后输出的一些线程堆栈信息;可以很快定位到问题出在哪里。
Step 4: 分析 SYSTEM LOG
系统 Log 详细输出各种 log,可以找出相关 log 进行逐一分析。
bugreport 实例分析
按照以上的 log 分析步骤进行相关分析:
Step1: 查看系统版本信息
确认问题系统环境。
Step2: 查看 CPU/MEMORY 的使用情况
(Android 使用 procrank 和 dumpsys meminfo 分析内存占用情况),由日志以下内容可知,系统内存空间剩余近 700M。
MemTotal: 1048576 kB
MemAvailable: 756304 kB
Cached: 110392 kB
------ CPU INFO (top -n 1 -d 1 -m 30 -t) ------
User 70 + Nice 3 + Sys 70 + Idle 250 + IOW 4 + IRQ 0 + SIRQ 0 = 397
cpu 使用情况:指的是一个最小时间片内所占用的时间,单位是 jiffies。
- user 表示处于用户态的运行时间,不包含优先值为负的进程
- Nice: 优先值为负的进程占 cpu 的时间
- sys:处于核心态的运行时间
- Idle:除 IO 等待时间外的其他等待时间
User 18%, System 17%, IOW 1%, IRQ 0%
//cpu 占用率:user 用户进程,system 系统进程,IOW 就是 io 等待时间,IRQ 硬中断时间
Buffers: 6620 kB
MemFree: 714776 kB
------ MEMORY INFO (/proc/meminfo) ------
PID TID PR CPU% S VSS RSS PCY UID Thread Proc
9 9 0 7% S 0K 0K root migration/0
2271 2271 3 4% S 505916K 37700K fg system system:ui system:ui
- PID: 进程在系统中的 ID
- PR: 优先级(数值越小,优先级越高)
- CPU%: 当前瞬时所以使用 CPU 占用率
- S: 进程的状态,其中 S 表示休眠,R 表示正在运行,Z 表示僵死状态,N 表示该进程优先值是负数
- VSS: Virtual Set Size 虚拟耗用内存(包含共享库占用的内存)
- RSS:实际使用的物理内存,包括共享库
- UID: 运行当前进程的用户 id
- Thread: 程序当前运行的线程
Procrank 分析
procrank 是按照内存占用情况对进程进行排序。因为它需要遍历/proc
下的所有进程获取内存占用情况,所以在运行时候需要有 root 权限。可用排序的有 VSS、RSS、PSS、USS。
- PSS:Proportional Set Size,实际使用的物理内存,共享库按比例分配
- USS:Unique Set Size,进程独占的物理内存,不计算共享库,也可以理解为将进程杀死能释放出的内存。USS 是针对某个进程开始有可疑内存泄露的情况,进行检测的最佳数字。怀疑某个程序有内存泄露可以查看这个值是否一直有增加。
一般 VSS >= RSS >= PSS >= USS
dumpsys meminfo 内存信息示例
(也可直接使用此命令查看)
Total PSS by process:
38102 kB: com.android.smart.terminal.iptv (pid 2231 / activities)
21334 kB: zygote (pid 1506)
21199 kB: system (pid 1894)
10878 kB: com.android.settings (pid 2358)
9809 kB: mediaserver (pid 1508)
9607 kB: android.process.media (pid 2100)
………………..
121 kB: servicemanager (pid 1501)
Total PSS by OOM adjustment:
62627 kB: Native
21334 kB: zygote (pid 1506)
9809 kB: mediaserver (pid 1508)
5375 kB: smbd (pid 2579)
4360 kB: nmbd (pid 2588)
2497 kB: surfaceflinger (pid 1505)
2255 kB: smbd (pid 2587)
1589 kB: logcat (pid 2023)
………………
121 kB: servicemanager (pid 1501)
21199 kB: System
21199 kB: system (pid 1894)
77156 kB: Persistent
38102 kB: com.android.smart.terminal.iptv (pid 2231 / activities)
5981 kB: com.hisilicon.android.inputmethod.remote (pid 2165)
5839 kB: com.hisilicon.dlna.dmr (pid 2208)
5710 kB: com.hisilicon.android.hiRMService (pid 2181)
5595 kB: com.android.smart.terminal.settings (pid 2217)
5547 kB: com.androidmov.tr069 (pid 2248)
5220 kB: com.android.smart.terminal.iptv.aidl:remote (pid 2325)
5162 kB: com.hisilicon.dlna.dms (pid 2191)
5731 kB: A Services
5731 kB: com.android.music (pid 2549)
35189 kB: Cached
10878 kB: com.android.settings (pid 2358)
9607 kB: android.process.media (pid 2100)
9080 kB: system:ui (pid 2271)
5624 kB: com.explorer (pid 2627)
Total PSS by category:
55941 kB: .so mmap
44064 kB: Dalvik
28413 kB: .dex mmap
20933 kB: Native
17885 kB: Dalvik Other
………………
Total RAM: 1048576 kB
Free RAM: 791329 kB (35189 cached pss + 156792 cached + 599348 free)
Used RAM: 194269 kB (166713 used pss + 7108 buffers + 1036 shmem + 19412 slab)
Lost RAM: 62978 kB
ZRAM: 4 kB physical used for 0 kB in swap (102396 kB total swap)
Tuning: 192 (large 256), oom 81920 kB, restore limit 27306 kB (high-end-gfx)
打印某个程序内存信息,可加包名,例如:
dumpsys meminfo com.android.launcher
补充:
Android 程序内存被分为两个部分:native 和 dalvik。dalvik 即为 java 堆,我们创建的对象是在这里面分配的,而 bitmap 是直接在 native 上分配的,对于内存的限制 native+dalvik 不能超过最大限制。Android 程序内存一般限制在 16M,当然也有 24M 的。
从上信息对于分析内存泄露,内存溢出都有极大的作用,从以上信息可以看到该应用程序占用的 native 和 dalvik,当TOTAL 12239 7760 736 0 9340 7178 1993
超过内存最大限制时会出现 OOM 错误。
Step 3: traces 日志分析
(traces 日志在data/anr
目录中)
可查询虚拟机信息:包括进程 / 线程的跟踪信息,用来跟踪进程和线程的具体点。格式如下:
DALVIK THREADS:"main" prio=5 tid=1
SUSPENDED //主线程挂起
| state=S schedstat=( 0 0 0 ) utm=78 stm=9 core=0
| group="main" sCount=1 dsCount=0 obj=0x417becc0 self=0x1a8d4f0
(mutexes: tll=0 tsl=0 tscl=0 ghl=0)
| sysTid=1894 nice=-2 sched=0/0 cgrp=apps handle=1073893740
at android.util.SparseArray.<init>(SparseArray.java:~72)
at android.net.wifi.WifiManager.<clinit>(WifiManager.java:554)
at android.app.ContextImpl$ServiceFetcher.getService(ContextImpl.java:269)
at android.net.wifi.WifiStateTracker.startMonitoring(WifiStateTracker.java:96)
at com.android.server.ConnectivityService.<init>(ConnectivityService.java:455)
at com.android.server.SystemServer.main(SystemServer.java:1308) at java.lang.reflect.Method.invoke(Method.java:515)
at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:650)
at dalvik.system.NativeStart.main(Native Method)
at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:834)
at java.lang.reflect.Method.invokeNative(Native Method)
at com.android.server.ServerThread.initAndLoop(SystemServer.java:594)
at com.android.server.ConnectivityService.<init>(ConnectivityService.java:649)
at android.app.ContextImpl.getSystemService(ContextImpl.java:1712)
at android.app.ContextImpl$44.createService(ContextImpl.java:-1)
at android.util.SparseArray.<init>(SparseArray.java:61)
根据以上日志找出导致 main 主线程 suspend 的类WifiStateTracker
中对应的具体 96 行代码和ContextImpl
中 1712 行代码可知,产生主线程 suspend 是 wifi 监控线程检测不到 wifi 连接。
Step 4: 系统日志(SYSTEM LOG)
详细输出各种 log:
日志格式如下:
------ SYSTEM LOG (logcat -v threadtime -d *:v) ------
--------- beginning of /dev/log/system
01-01 08:00:02.352 1502 1502 I Vold : Vold 2.1 (the revenge) firing up
01-01 08:00:00.037 1502 1502 D Vold : [-vold_debug-86] :the service.vold.status is Normal
01-01 08:00:00.044 1502 1502 D Vold : [-vold_debug-122] :defaultVolume = /storage/emulated/0
01-01 08:00:00.044 1502 1502 D Vold : [-vold_debug-139] :bind mount /mnt/sdcard to /storage/emulated/0 ok !
01-01 08:00:00.044 1502 1502 D VoldCmdListener: [-vold_debug-785] :IsoMountCmd created!
01-01 08:00:00.045 1502 1502 I Vold : Load vold.emmc.fstab
01-01 08:00:00.045 1502 1502 D Vold : [-vold_debug-562] :multi_mount!
01-01 08:00:00.045 1502 1502 D Vold : [-vold_debug-261] :addVolumeDir
01-01 08:00:00.045 1502 1502 D Vold : [-vold_debug-585] :multi_mount!!
01-01 08:00:00.046 1502 1502 E Vold : Vold is Running
小总结
一、最常用的日志抓取
日常调试就抓:
- 应用日志(自己写的代码日志):
adb logcat -b main -v time > /sdcard/应用日志.log
- 系统日志(系统服务、Framework 层):
adb logcat -b system -v time > /sdcard/系统日志.log
- 完整日志(啥都有,出问题优先抓这个):
adb logcat -b main -b system -b radio -b events -v time > /sdcard/全日志.log
- (高级)内核日志(需 root 权限):
先输adb root
获取权限,再输adb shell "cat /proc/kmsg > /sdcard/内核日志.log"
二、日志级别
日志分等级,找问题主要看这两个:
- E(错误):比如应用崩溃、功能报错,日志里带
E/
标记,必看。 - W(警告):可能出问题的前兆,比如参数不对、资源不够,带
W/
标记,留意。
三、快速过滤日志的 3 个技巧
日志太多?这么筛:
- 只看错误:
adb logcat *:E
- 只看自己的应用:
先查应用包名(比如com.myapp
),再输:
adb logcat --package=com.myapp
- 搜关键词:
找崩溃就搜crash
,找网络问题搜http
,命令:
adb logcat | grep "关键词"
(Windows 用find
代替grep
)
四、查问题的关键工具和文件
- 看内存 / CPU:输
adb shell dumpsys meminfo 包名
查内存,dumpsys cpuinfo
查 CPU 占用,卡顿时必看。 - ANR(应用无响应):日志里搜
ANR in
,再用adb pull /data/anr/traces.txt
拉取详细文件,看主线程是不是卡了。 - 应用崩溃:日志里找
FATAL EXCEPTION
,下面的堆栈会告诉你 “哪个文件哪行代码错了”(比如MainActivity.java:42
)。
五、分析步骤 4 步
- 清缓存:先输
adb logcat -c
清空旧日志,避免干扰。 - 复现问题:操作手机让问题出现(比如点按钮崩溃)。
- 抓日志:用上面的命令把日志存到文件。
- 搜关键:在日志里搜
E/
、crash
、ANR
,顺着堆栈找原因。