Android日志分析

mac2024-01-27  31

近期开始接触Android相关内容,从基础开始学习吧。

一、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 adb logcat *:I //显示所有优先级大于等于“info”的日志 adb logcat *:V //显示所有优先级大于等于“verbose”的日志 adb logcat ActivityManager:I  *:S  //仅输出标记为“ActivityManager”且优先级大于等于“Info”的日志

分类展示:

adb logcat -s papaya  //显示 papaya 的日志信息 adb logcat -v tag  //按照标签来打印日志信息 adb logcat -v thread  // 显示 I,D,E等日志类型的进程ID、线程ID

grep 过滤(windows 可用find代替)

adb logcat | grep PID  //根据进程id来过滤 adb logcat | grep -i myapp  //根据字符串来过滤,并忽略大小写 adb logcat | grep "^..MyApp"  //仅匹配 tag 过滤, tag 是一行开头的第三个字符开始

三、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 -----------------------------------------------------------------------------------

      根据以上几种日志类型可以分析系统的内存信息、CPU信息、各种线程堆栈信息以及系统详细信息。基于此可以对相关问题进行分析排查。

最新回复(0)