|
|
|
Android log系统 |
|
|
|
|
|
light |
|
2011/11/20 |
|
Android 系统log抓取，实现原理分析 |
一 概述
本文档主要是供Android开发人员使用，特别是Framework开发。因为Framework中95%以上的问题都是靠分析log解决的，所以开发人员必须对android整个log系统十分清楚。什么问题抓什么log, 使用什么工具抓Log，如何分析log, 如何在代码中添加log.
二DDMS log
关于ddms是如何工作的和ddms的详细功能，见下面android sdk中文档详细介绍：
F: 2 Android 1_SDKGingerbread2.3docs-2.3_r01-linuxguidedeveloping oolsddms.html
Ddms 工具中打印log的几个菜单如下：
Device -> Show process status…
Device -> Dump device state…
Device -> Dump app state…
Device -> Dump radio state…
Device -> Run logcat…
1、 Show process status…菜单
等效于在adb shell下执行adb shell ps –x 命令，该命令打印出进程的详细信息，如下：
USER PID PPID VSIZE RSS WCHAN PC NAME
root 1 0 268 180 c009b74c 0000875c S /init (u:2, s:371)
root 2 0 0 0 c004e72c 00000000 S kthreadd (u:0, s:1)
root 3 2 0 0 c003fdc8 00000000 S ksoftirqd/0 (u:0, s:0)
root 4 2 0 0 c004b2c4 00000000 S events/0 (u:0, s:39)
root 5 2 0 0 c004b2c4 00000000 S khelper (u:0, s:0)
root 6 2 0 0 c004b2c4 00000000 S suspend (u:0, s:0)
USER 用户名，即用户所在组
PID 进程ID（Process ID）
PPID 父进程的进程ID（Parent Process id）
VSZ 进程所使用的虚拟内存的大小（Virtual Size）
RSS 进程使用的驻留集大小或者是实际内存的大小，Kbytes字节。
WCHAN 进程正在睡眠的内核函数名称；该函数的名称是从/root/system.map文件中获得的
Exploring Processes
You can see the output of ps -x for a specific VM by selecting Device > Show process status... in the menu bar.
2、 Dump device state…菜单
等效于执行 /system/bin/dumpstate /proc/self/fd/0
等效于执行adb shell dumpstate命令
To run dumpstate from Dalvik, select Device > Dump device state... in the menu bar.
3、 Dump app state…菜单
等效于执行adb shell dumpsys命令
输出android服务状态信息，即输出服务中dump函数的log.
4、 Dump radio state…菜单
等效于执行adb shell cat /data/logs/radio命令
Examine Radio State
By default, radio state is not output during a standard logcat (it is a lot of information). To see radio information, either click Device > Dump radio state... or run logcat as described in Logging Radio Information.
5、 Run logcat…菜单
等效于执行adb logcat
To run dumpsys (logcat) from Dalvik, select Device > Run logcat... in the menu bar.
总结：除了Run logcat…菜单是实时输出设备中的log外，其他菜单都是输出设备中缓存的log
三 Adb Log
Android sdk文档中对adb的介绍见下：
F: 2 Android 1_SDKGingerbread2.3docs-2.3_r01-linuxguidedeveloping oolsadb.html
在adb 1.0.26版本共有2条命令打印log,如下：
adb logcat [ <filter-spec> ] - View device log
adb bugreport - return all information from the device
that should be included in a bug report.
Adb logcat常用命令
logcat -c 清除已有log信息
logcat -b main 显示主缓冲区的log
logcat -b radio 显示无线缓冲区的log
logcat -b events 显示事件缓冲区的log
logcat -f [filename] 将log保存到指定的文件中，例如 logcat -b radio -f /data/radio.log
比较常用的是显示时间:logcat -v time &
logcat -g 查看缓冲区的大小
logcat -g main
logcat -g radio
logcat -g events
logcat打印/dev/log设备下的三个文件 radio, events, main数据
logcat默认是输出main缓冲区的log
控制日志输出格式
日志信息包括了许多元数据域包括标签和优先级。可以修改日志的输出格式，所以可以显示出特定的元数据域。可以通过 -v 选项得到格式化输出日志的相关信息.
brief — Display priority/tag and PID of originating process (the default format).
process — Display PID only.
tag — Display the priority/tag only.
thread — Display process:thread and priority/tag only.
raw — Display the raw log message, with no other metadata fields.
time — Display the date, invocation time, priority/tag, and PID of the originating process.
long — Display all metadata fields and separate messages with a blank lines.
当启动了logcat ，你可以通过-v 选项来指定输出格式:
[adb] logcat [-v <format>]
此外，adb shell cmd, cmd为/system/bin目录下抓log的可执行程序，如dumpsys , dumpstate等
Adb下的log命令：
Adb logcat
Adb bugreport
Adb shell dumpsys
Adb shell dumpstate
Adb shell dmesg //导出当前缓存的kernel log
Adb shell kmsgcat //实时查看kernel log
其他查看系统当前信息命令
Adb shell ps //查看系统进程信息，可以加很多有用信息
Adb shell pm //查看package相关信息
Adb shell am //启动apk应用
Adb shell setprop //设置系统属性
Adb shell getprop //查看所有系统属性
Adb shell reboot
Adb shell kill //通过进程ID杀死指定的进程
Adb shell top //查看当前运行进程信息
Adb shell vmstat //查看虚拟机信息
Adb shell bootanimation //播放开机动画
Adb shell df //查看分区信息
Adb shell monkey //跑自动化测试用例
四 保存在手机的Log
1、手机dropbox默认路径：
/data/system/dropbox/
实现机制：
log文件什么场景产生？
Log文件分析：
2、手机anr日志默认路径：
/data/anr/
实现机制：
log文件什么场景产生？
Log文件分析：
4、tombstones路径：
/data/tombstones
log文件什么场景产生？
Log文件分析：
五 如何实现后台抓Log
如：
adb logcat -v time -r 1024 -n 16 -f /sdcard/bugreports/applogcat-log
六 log执行程序实现机制
1、Logcat
LogCat是在文件system/core/logcat/logcat.cpp中实现的。
从Logger设备驱动的实现知道，Log的读取是阻塞的操作，亦即，有数据可用，读出数据；否则，读操作会被BLOCK，相应的读进程也会被挂起等待。下面看应用程序LogCat中如何实现读的，这可能需要不断回头与写操作和驱动实现结合来看。
看具体实现之前，先看一个logcat中定义的重要的结构体log_device_t。其中的重要的成员在后面用到的时候再具体解释。
Android的Logcat命令详解的命令参数-b <buffer>知道，logcat是可以通过参数来指定对哪个buffer(main/radio/event)进行操作的。Logcat的b参数解析的地方，是通过传递进来的参数（main/radio/event）来创建了一个上面的结构变量，而这些结构通过log_device_t.next链接起来
因为logcat可能会同时操作多个Buffer，而read()会阻塞读取进程，对其他Buffer的读取就不能进行，所以这里用select()来判断可读取的Buffer。
2、Bugreport
I: 0_AndriodSourceandroid-gingerbread-srcframeworksasecmdsugreport
#include <cutils/properties.h>
#include <cutils/sockets.h>
int main(int argc, char *argv[]) {
char buffer[65536];
int i, s;
/* start the dumpstate service */
property_set("ctl.start", "dumpstate");//启动dumpstate服务
/* socket will not be available until service starts */
for (i = 0; i < 10; i++) {
s = socket_local_client("dumpstate",
ANDROID_SOCKET_NAMESPACE_RESERVED,
SOCK_STREAM);
if (s >= 0)
break;
/* try again in 1 second */
sleep(1);
}
if (s < 0) {
fprintf(stderr, "Failed to connect to dumpstate service ");
exit(1);
}
while (1) {
int length = read(s, buffer, sizeof(buffer));
if (length <= 0)
break;
fwrite(buffer, 1, length, stdout);
}
close(s);
return 0;
}
原理：启动dumpstate服务，通过socket连接dumpstate服务，然后从socket中不断读取dumpstate侧的log打印出来
通过代码分析和实际对比分析，发现bugreport输出的log和dumpstate输出的log完全一致。
3、Dumpstate
I: 0_AndriodSourceandroid-gingerbread-srcframeworksasecmdsdumpstate
输出的信息包括：
1、 版本信息
2、 系统状态信息：CPU 内存 进程 系统属性 等
3、 Logcat信息
4、 Dumpsys输出的所以services信息
5、 ANR log信息
6、 Dmesg kernel log信息
会运行下面命令输出log
run_command("CPU INFO", 10, "top", "-n", "1", "-d", "1", "-m", "30", "-t", NULL);
run_command("PROCRANK", 20, "procrank", NULL);
run_command("SYSTEM LOG", 20, "logcat", "-v", "time", "-d", "*:v", NULL);
run_command("EVENT LOG", 20, "logcat", "-b", "events", "-v", "time", "-d", "*:v", NULL);
run_command("RADIO LOG", 20, "logcat", "-b", "radio", "-v", "time", "-d", "*:v", NULL);
run_command("NETWORK INTERFACES", 10, "netcfg", NULL);
run_command("KERNEL LOG", 20, "dmesg", NULL);
run_command("VOLD DUMP", 10, "vdc", "dump", NULL);
run_command("SECURE CONTAINERS", 10, "vdc", "asec", "list", NULL);
run_command("PROCESSES", 10, "ps", "-P", NULL);
run_command("PROCESSES AND THREADS", 10, "ps", "-t", "-p", "-P", NULL);
run_command("LIBRANK", 10, "librank", NULL);
run_command("FILESYSTEMS & FREE SPACE", 10, "df", NULL);
run_command("LAST RADIO LOG", 10, "parse_radio_log", "/proc/last_radio_log", NULL);
run_command("DUMPSYS", 60, "dumpsys", NULL);
4、Dumpsys
I: 0_AndriodSourceandroid-gingerbread-srcframeworksasecmdsdumpsys
const size_t N = services.size();
if (N > 1) {
// first print a list of the current services
aout << "Currently running services:" << endl;
for (size_t i=0; i<N; i++) {
sp<IBinder> service = sm->checkService(services[i]);
if (service != NULL) {
aout << " " << services[i] << endl;
}
}
}
for (size_t i=0; i<N; i++) {
sp<IBinder> service = sm->checkService(services[i]);
if (service != NULL) {
if (N > 1) {
aout << "------------------------------------------------------------"
"-------------------" << endl;
aout << "DUMP OF SERVICE " << services[i] << ":" << endl;
}
int err = service->dump(STDOUT_FILENO, args);//调用每个service中的dump()方法输出log
if (err != 0) {
aerr << "Error dumping service info: (" << strerror(err)
<< ") " << services[i] << endl;
}
} else {
aerr << "Can't find service: " << services[i] << endl;
}
}
输出log信息代码如上，结合实际log分析，dumpsys输出系统服务dump信息
七 其他方法技巧
1、 通过设置系统属性打开log开关
如有如下打印log的代码：
if (Log.isLoggable(TAG, Log.DEBUG)) {
Log.d(TAG, "Redirect requested but no Location "
+ "specified.");
}
我们只需要通过设置系统属性就可以打印出这个log，而不用修改代码。可以通过setprop命令或修改build.prop来达到目的。具体见Log.java中的介绍：
/**
* Checks to see whether or not a log for the specified tag is loggable at the specified level.
*
* The default level of any tag is set to INFO. This means that any level above and including
* INFO will be logged. Before you make any calls to a logging method you should check to see
* if your tag should be logged. You can change the default level by setting a system property:
* 'setprop log.tag.<YOUR_LOG_TAG> <LEVEL>'
* Where level is either VERBOSE, DEBUG, INFO, WARN, ERROR, ASSERT, or SUPPRESS. SUPRESS will
* turn off all logging for your tag. You can also create a local.prop file that with the
* following in it:
* 'log.tag.<YOUR_LOG_TAG>=<LEVEL>'
* and place that in /data/local.prop.
*
* @param tag The tag to check.
* @param level The level to check.
* @return Whether or not that this is allowed to be logged.
* @throws IllegalArgumentException is thrown if the tag.length() > 23.
*/
public static native boolean isLoggable(String tag, int level);
1. 查看当前堆栈
1) 功能：在程序中加入代码，使可以在logcat中看到打印出的当前函数调用关系
2) 方法：
new Exception(“print trace”).printStackTrace();
2. MethodTracing
1) 功能：用于热点分析和性能优化，分析每个函数占用的CPU时间，调用次数，函数调用关系等
2) 方法：
a) 在程序代码中加入追踪开关
import android.os.Debug;
……
android.os.Debug.startMethodTracing(“/data/tmp/test”); // 先建/data/tmp目录
…… // 被追踪的程序段
android.os.Debug.stopMethodTracing();
b) 编译，运行后，设备端生成/data/tmp/test.trace文件
c) 把trace文件复制到PC端
$ adb pull /data/tmp/test.trace ./
d) 使用android自带工具分析trace文件
$ $ANDROID_SRC/out/host/linux-x86/bin/traceview test.trace
此时可看到各个函数被调用的次数CPU占用率等信息
e) 使用android自带工具分析生成调用关系类图
$ apt-get install graphviz # 安装图片相关软件
$ANDROID_SRC/out/host/linux-x86/bin/dmtracedump -g test.png test.trace
此时目录下生成类图test.png
3) 注意
trace文件生成与libdvm模块DEBUG版本相冲突，所以此方法只适用于对非DEBUG版本模拟器的调试，否则在分析trace文件时会报错
3. HProf (Heap Profile)
1) 功能：
用于java层面的内存分析，显示详细的内存占用信息，指出可疑的内存泄漏对象
2) 方法：
a) 在代码中加入dump动作
import android.os.Debug;
import java.io.IOException;
……
try {
android.os.Debug.dumpHprofData(“/data/tmp/input.hprof”); // 先建/data/tmp目录
} catch (IOException ioe) {
}
b) 把hprof文件复制到PC端
$ adb pull /data/tmp/input.hprof ./
c) 使用命令hprof-conv把hprof转成MAT识别的标准的hprof
$ $ANDROID_SRC/out/host/linux-x86/bin/hprof-conv input.hprof output.hprof
d) 使用MAT工具看hprof信息
下载MAT工具：http://www.eclipse.org/mat/downloads.php
用工具打开output.hprof
3) 注意：此工具只能显示java层面的，而不能显示Ｃ层的内存占用信息
4. SamplingProfile (android 2.0上版本使用)
1) 功能
每隔Ｎ毫秒对当前正在运行的函数取样，并输出到log中
2) 在代码中加入取样设定
import dalvik.system.SamplingProfiler
……
SamplingProfile sp = SamplingProfiler.getInstance();
sp.start(n); // n为设定每秒采样次数
sp.logSnapshot(sp.snapshot());
……
sp.shutDown();
它会启一个线程监测，在logcat中打印信息
5. 用发系统信号的方式取当前堆栈情况和内存信息
1) 原理
dalvik虚拟机对SIGQUIT和SIGUSR1信号进行处理(dalvik/vm/SignalCatcher.c)，分别完成取当前堆栈和取当前内存情况的功能
2) 用法
a) $ chmod 777 /data/anr -R # 把anr目录权限设为可写
$ rm /data/anr/traces.txt # 删除之前的trace信息
$ ps # 找到进程号
$ kill -3 进程号 # 发送SIGQUIT信号给该进程，此时生成trace信息
$ cat /data/anr/traces.txt
功能实现：遍历thread list(dalvik/vm/Thread.c:dvmDumpAllThreadEx())，并打印当前函数调用关系(dalvik/vm/interp/Stack.c:dumpFrames())
b) $ chmod 777 /data/misc -R
$ ps # 找到进程号
$ kill -10 进程号 # 发送SIGQUIT信事信号给该进程，此时生成hprof信息
$ ls /data/misc/*.hprof
此时生成hprf文件，如何使用此文件，见第二部分(HProf)
注意：hprof文件都很大，注意用完马上删除，以免占满存储器
6. logcat及原理
1) android.util.Log利用println的标准java输出词句，并加前缀I/V/D….
2) dalvik利用管道加线程的方式，先利用dup2把stdout和stderr重定向到管理中(vm/StdioConverter.c:dvmstdioConverterStartup)，然后再启动一个线程从管道另一端读出内容(dalvik/vm/StdioConverter.c:stdioconverterThreadStart())，使用LOG公共工具（system/core/liblog/logd_write.c: __android_log_print()）输出到/dev/log/*中去
LogCat是在文件system/core/logcat/logcat.cpp中实现的
7. monkey
1) monkey是一个android自带的命令行工具。它向系统发送伪随机的用户事件流，实现对正在开发的应用程序进行压力测试。
2) 方法
在设备端打开setting界面
$ adb shell
# monkey -p com.android.settings -v 500
此时可以看到界面不断被切换
8. 其它小工具
具体见android.os.Debug中提供的工具
1) 取毫微秒级的时间，用于计算时间
threadCpuTimeNanos()
2) 统计两点间的内存分配情况
startAllocCounting()
stopAllocCounting()
getGlobalAllocCount()
get…..
3) 打印当前已load的class
getLoadedClassCount()
printLoadedClasses() 它需要打开NDEBUG功能才能打开system/core/中Log功能