本文基于Android7.1代码分析
- 一.查看EventLog
- 二.logtags生成
- 2.1开机event log分析
- 1.获取开机时的event log:
- 2.boot_progress_start是哪里输出的?
- 2.2应用启动event log分析
- 1.获取应用启动event log
- 2.am_create_activity在哪里输出的
- 3.输出log表示什么
一.查看EventLog
使用命令:
logcat -b events
二.logtags生成
2.1开机event log分析
1.获取开机时的event log:
logcat -b events | grep boot_progress
输出:
I boot_progress_start: 20726
I boot_progress_preload_start: 23255
I boot_progress_preload_end: 26806
I boot_progress_system_run: 27135
I boot_progress_pms_start: 27946
I boot_progress_pms_system_scan_start: 28447
I boot_progress_pms_data_scan_start: 29647
I boot_progress_pms_scan_end: 29958
I boot_progress_pms_ready: 30910
I boot_progress_ams_ready: 35811
I boot_progress_enable_screen: 38542
boot_progress_start表示Linux kernel启动到Zygote进程启动的时间,包含从kernel启动到Init启动Zygote的时间,接下来我们就以boot_progress_start为例来分析这条日志是如何输出的。
2.boot_progress_start是哪里输出的?
在/system/core/logcat/event.logtags找到了boot_progress_start的定义
# The entries in this file map a sparse set of log tag numbers to tag names.
# This is installed on the device, in /system/etc, and parsed by logcat.
...
# Device boot timings. We include monotonic clock values because the
# intrinsic event log times are wall-clock.
#
# Runtime starts:
3000 boot_progress_start (time|2|3)
从注释可以看出这个logtags文件是用于日志标记号映射到标记名,并且安装在/system/etc下。在/system/etc下查找到event-log-tags文件,我们看下event-log-tags是如何生成的。
在build/soong/java/gen.go下:
pctx.SourcePathVariable("logtagsCmd", "build/tools/java-event-log-tags.py")
pctx.SourcePathVariable("mergeLogtagsCmd", "build/tools/merge-event-log-tags.py")
java-event-log-tags.py:生成一个java类,其中包含给定输入文件中每个事件日志标记的常量。
merge-event-log-tags.py:将零个或多个事件日志标记文件合并在一起,生成一个单独的输出文件,去掉注释。检查没有标签号冲突,如果有就失败。
我们知道boot_progress对应的id是3000,去framework下查找
grep -rn 3000
base/core/jni/AndroidRuntime.cpp:994: const int LOG_BOOT_PROGRESS_START = 3000;
看下代码
void AndroidRuntime::start(const char* className, const Vector<String8>& options, bool zygote)
{
...
const int LOG_BOOT_PROGRESS_START = 3000;
LOG_EVENT_LONG(LOG_BOOT_PROGRESS_START, ns2ms(systemTime(SYSTEM_TIME_MONOTONIC)));
}
同样,我们在
frameworks/base/core/java/com/android/internal/os/ZygoteInit.java找到了
EventLog.writeEvent(LOG_BOOT_PROGRESS_PRELOAD_START, SystemClock.uptimeMillis());
2.2应用启动event log分析
1.获取应用启动event log
logcat -b events | grep am_
输出:
I am_create_task: [0,364]
I am_create_activity: [0,165832734,364,com.android.settings/.Settings,android.intent.action.MAIN,NULL,NULL,270532608]
I am_focused_stack: [0,1,0,startedActivity setFocusedActivity]
I am_focused_activity: [0,com.android.settings/.Settings,startedActivity]
I am_pause_activity: [0,102587883,com.android.launcher3/.Launcher]
I am_on_paused_called: [0,com.android.launcher3.Launcher,handlePauseActivity]
I am_restart_activity: [0,165832734,364,com.android.settings/.Settings]
I am_on_resume_called: [0,com.android.settings.Settings,LAUNCH_ACTIVITY]
I am_activity_launch_time: [0,165832734,com.android.settings/.Settings,825,825]
I am_stop_activity: [0,102587883,com.android.launcher3/.Launcher]
I am_on_stop_called: [0,com.android.launcher3.Launcher,handleStopActivity]
I am_pss : [5733,10023,com.android.launcher3,12664832,9179136,0]
接下来我们以am_create_activity为例,分析log的输出,以及log的含义。
2.am_create_activity在哪里输出的
前面讲到java-event-log-tags.py会将logtags文件转换成java文件
- 1.先在/out/target/common/目录下查找am_create_activity
find . -name EventLogTags.java | xargs grep am_create_activity
找到了:
./obj/JAVA_LIBRARIES/services.core_intermediates/src/java/com/android/server/am/EventLogTags.java: /** 30005 am_create_activity (User|1|5),(Token|1|5),(Task ID|1|5),(Component Name|3),(Action|3),(MIME Type|3),(URI|3),(Flags|1|5) */
看下这个文件:
/** 30005 am_create_activity (User|1|5),(Token|1|5),(Task ID|1|5),(Component Name|3),(Action|3),(MIME Type|3),(URI|3),(Flags|1|5) */
public static final int AM_CREATE_ACTIVITY = 30005;
public static void writeAmCreateActivity(int user, int token, int taskId, String componentName, String action, String mimeType, String uri, int flag s) {
android.util.EventLog.writeEvent(AM_CREATE_ACTIVITY, user, token, taskId, componentName, action, mimeType, uri, flags);
}
- 2.接下来去framework下查找哪里使用了writeAmCreateActivity
grep -rn writeAmCreateActivity
没有查找到,那就查AM_CREATE_ACTIVITY
grep -rn AM_CREATE_ACTIVITY
输出:
services/core/java/com/android/server/am/ActivityStarter.java:1242: EventLogTags.AM_CREATE_ACTIVITY, mStartActivity, mStartActivity.task);
看下代码:
ActivityStack.logStartActivity(EventLogTags.AM_CREATE_ACTIVITY, mStartActivity, mStartActivity.task);
再来看下logStartActivity方法:
static final void logStartActivity(int tag, ActivityRecord r,
TaskRecord task) {
final Uri data = r.intent.getData();
final String strData = data != null ? data.toSafeString() : null;
EventLog.writeEvent(tag,
r.userId, System.identityHashCode(r), task.taskId,
r.shortComponentName, r.intent.getAction(),
r.intent.getType(), strData, r.intent.getFlags());
}
3.输出log表示什么
由上面的输出行代码,再来看看
[0,165832734,364,com.android.settings/.Settings,android.intent.action.MAIN,NULL,NULL,270532608]
这就明白了
userId=0
identityHashCode=0,165832734
taskId=364
shortComponentName=com.android.settings/.Settings
上面的方式是通过查找代码来看出log含义。其实如果只是看log含义不需要这么麻烦,在/system/etc/event-log-tags可以看到
30005 am_create_activity (User|1|5),(Token|1|5),(Task ID|1|5),(Component Name|3),(Action|3),(MIME Type|3),(URI|3),(Flags|1|5)
这里的数字是什么意思呢?在framework下查找:
find . -name *.logtags | xargs grep am_create_activity
输出:
./services/core/java/com/android/server/am/EventLogTags.logtags:30005 am_create_activity (User|1|5),(Token|1|5),(Task ID|1|5),(Component Name|3),(Action|3),(MIME Type|3),(URI|3),(Flags|1|5)
这个文件开头就告诉我们去system/core/logcat/event.logtags看文件格式的描述
前面在分析开启启动log时,我们就看过这个文件。此时,我们再来看看。这个文件告诉我们描述格式是:
(<name>|data type[|data unit])
- data type表示:
1: int
2: long
3: string
4: list
5: float
- data unit表示:
1: Number of objects
2: Number of bytes # int/long类型数据的默认值是2(字节)。
3: Number of milliseconds
4: Number of allocations
5: Id
6: Percent
- 实例分析
(User|1|5)表示:User是一个int类型的id
(Component Name|3)表示是一个string