启动时间分析

本文面向已经读过 Zygote预加载、SystemServer.run、BootPhase阶段和服务启动耗时的读者。此前文章解释了单个进程和服务内部的启动机制；本文解决另一个问题：当一次冷启动变慢时，怎样把 Zygote、SystemServer、PMS、AMS、屏幕启用和 boot animation 放进同一条可比较的时间线。

本文不重复每个 SystemService 的 onStart() 实现，也不把一次设备日志中的数字当作通用基准。读完后，你应能判断一个时间点由谁写入、使用哪一种时钟、消费者如何读取，以及一次优化究竟移动了关键路径，还是只改变了某个局部指标。

1. 三种时间源

Android 启动分析至少涉及三种不同粒度的时间源：

时间源	owner	数据形态	适合回答的问题	不能单独证明什么
EventLog 里程碑	Zygote、SystemServer、PMS、AMS、ATMS	单个 monotonic 时间点	哪个跨进程阶段整体后移	阶段内部哪一行代码慢
Trace/Timing	当前线程与 Perfetto	嵌套 section、调度与 duration	主线程、异步任务、Binder 或 I/O 卡在哪里	用户何时真正看到可交互桌面
Bootchart	init 内的采样线程	`/proc` CPU、磁盘和进程快照	哪个进程何时出现、CPU/I/O 是否拥塞	Java 方法、Binder transaction 的精确耗时

三者不是互相替代。正确的顺序通常是：先用 EventLog 判断回归落在哪个大区间，再用 Bootchart 判断它是否伴随系统级 CPU/I/O 竞争，最后进入 Perfetto 或 SystemServerTiming 找到具体 section。

这里的“终点”必须在实验前定义。测试启动框架就绪、屏幕启用、boot animation 结束和 Launcher 首帧是不同目标；如果基线用 wm_boot_animation_done，实验组就不能换成 boot_progress_enable_screen。

2. 事件里程碑

EventLog 行首的日期时间是 wall clock；boot_progress_* 的 payload 则按 tag 定义携带 monotonic 毫秒值。计算阶段差值应使用 payload，而不是可能被校时修改的日志前缀。

源码文件：system/logging/logcat/event.logtags

text

3000 boot_progress_start (time|2|3)
3020 boot_progress_preload_start (time|2|3)
3030 boot_progress_preload_end (time|2|3)

boot_progress_start 的写入方没有使用 tag 名符号，而是在 native AndroidRuntime::start() 中定义数值 3000；只搜索字符串 boot_progress_start 会漏掉真实入口。

源码文件：frameworks/base/core/jni/AndroidRuntime.cpp

cpp

static const String8 startSystemServer("start-system-server");
for (size_t i = 0; i < options.size(); ++i) {
    if (options[i] == startSystemServer) {
        primary_zygote = true;
        const int LOG_BOOT_PROGRESS_START = 3000;
        LOG_EVENT_LONG(LOG_BOOT_PROGRESS_START,
                ns2ms(systemTime(SYSTEM_TIME_MONOTONIC)));
    }
}

这个事件只由带 start-system-server 选项的 primary Zygote 写入，payload 使用不含 CPU suspend 的 SYSTEM_TIME_MONOTONIC。它标记 Android runtime/Zygote 启动入口，不是“内核结束”或“init 刚启动”。perfboot.py 还会读取设备上的 /system/etc/event-log-tags，过滤未知 tag；缺失事件在结果中填零并标记无效记录。

2.1 Zygote预加载

源码文件：frameworks/base/core/java/com/android/internal/os/ZygoteInit.java

java

final long startTime = SystemClock.elapsedRealtime();
final boolean isRuntimeRestarted = "1".equals(
        SystemProperties.get("sys.boot_completed"));

if (!enableLazyPreload) {
    bootTimingsTraceLog.traceBegin("ZygotePreload");
    EventLog.writeEvent(LOG_BOOT_PROGRESS_PRELOAD_START,
            SystemClock.uptimeMillis());
    preload(bootTimingsTraceLog);
    EventLog.writeEvent(LOG_BOOT_PROGRESS_PRELOAD_END,
            SystemClock.uptimeMillis());
    bootTimingsTraceLog.traceEnd();
}

预加载事件使用 uptimeMillis()，不包含 deep sleep；只有 eager preload 路径会在这里写入。64/32 位双 Zygote 还会产生同名事件的多个值，owner 是不同 PID。不能把日志中第一个 preload_start 与任意一个 preload_end 相减，必须按 PID 配对。

startTime 使用 elapsedRealtime()，供 StatsLog 的 Zygote init 事件使用；源码在同一个方法里并存两种时钟。变量相邻不等于时钟可直接混算。

2.2 系统服务与PMS

源码文件：frameworks/base/services/java/com/android/server/SystemServer.java

java

mStartCount = SystemProperties.getInt(SYSPROP_START_COUNT, 0) + 1;
mRuntimeStartElapsedTime = SystemClock.elapsedRealtime();
mRuntimeStartUptime = SystemClock.uptimeMillis();
mRuntimeRestart = mStartCount > 1;

SystemProperties.set(SYSPROP_START_COUNT, String.valueOf(mStartCount));
SystemProperties.set(SYSPROP_START_ELAPSED,
        String.valueOf(mRuntimeStartElapsedTime));
SystemProperties.set(SYSPROP_START_UPTIME,
        String.valueOf(mRuntimeStartUptime));
EventLog.writeEvent(EventLogTags.SYSTEM_SERVER_START,
        mStartCount, mRuntimeStartUptime, mRuntimeStartElapsedTime);

final long uptimeMillis = SystemClock.elapsedRealtime();
EventLog.writeEvent(EventLogTags.BOOT_PROGRESS_SYSTEM_RUN, uptimeMillis);

SYSTEM_SERVER_START 同时保存启动次数、uptime 和 elapsed realtime，可识别 system_server runtime restart，并给两种时钟提供同一时刻的锚点。紧接着的局部变量虽然名为 uptimeMillis，实际来自 elapsedRealtime()；阅读指标代码时应以调用函数为准，不能以变量名推断时钟。

BOOT_PROGRESS_SYSTEM_RUN 在 runtime restart 时仍会写入；只有后面的部分 StatsLog 上报受 !mRuntimeRestart、首次启动和升级条件限制。因此 events buffer 中出现 system_run 不一定代表一次完整冷启动。

PMS 的里程碑则继续使用 uptime。

源码文件：

frameworks/base/services/core/java/com/android/server/pm/PackageManagerService.java
frameworks/base/services/core/java/com/android/server/pm/InitAppsHelper.java

java

EventLog.writeEvent(EventLogTags.BOOT_PROGRESS_PMS_START,
        SystemClock.uptimeMillis());

long startTime = SystemClock.uptimeMillis();
EventLog.writeEvent(EventLogTags.BOOT_PROGRESS_PMS_SYSTEM_SCAN_START,
        startTime);
...
EventLog.writeEvent(EventLogTags.BOOT_PROGRESS_PMS_SCAN_END,
        SystemClock.uptimeMillis());
...
EventLog.writeEvent(EventLogTags.BOOT_PROGRESS_PMS_READY,
        SystemClock.uptimeMillis());

系统包扫描结束后，PMS 还会继续处理 settings 等状态，最后才写 pms_ready。data 分区的扫描起点由 InitAppsHelper 单独记录：

java

// frameworks/base/services/core/java/com/android/server/pm/InitAppsHelper.java
EventLog.writeEvent(EventLogTags.BOOT_PROGRESS_PMS_DATA_SCAN_START,
        SystemClock.uptimeMillis());
scanDirTracedLI(mPm.getAppInstallDir(), 0,
        mScanFlags | SCAN_REQUIRE_KNOWN,
        packageParser, mExecutorService, null);

pms_start → pms_ready 包含的不只是扫描；system_scan_start → data_scan_start → scan_end 才更接近 package scan 区间。若只看 pms_ready - pms_start，设置读取、权限处理、settings 写回等成本也会被归入 PMS。

2.3 AMS与屏幕

源码文件：

frameworks/base/services/core/java/com/android/server/am/ActivityManagerService.java
frameworks/base/services/core/java/com/android/server/wm/ActivityTaskManagerService.java

java

// ActivityManagerService.systemReady()
mProcessesReady = true;
Slog.i(TAG, "System now ready");
EventLogTags.writeBootProgressAmsReady(
        SystemClock.uptimeMillis());

ams_ready 的状态变化是 mProcessesReady=true：AMS 已清理更新进程，准备启动真实应用进程。它不是 boot completed，也不表示 Launcher 已绘制。

java

// ActivityTaskManagerService.LocalService
public void enableScreenAfterBoot(boolean booted) {
    writeBootProgressEnableScreen(SystemClock.uptimeMillis());
    mWindowManager.enableScreenAfterBoot();
    synchronized (mGlobalLock) {
        updateEventDispatchingLocked(booted);
    }
}

enable_screen 在调用 WindowManagerService.enableScreenAfterBoot() 之前写入，含义是“开始执行屏幕启用路径”，不是显示硬件已完成呈现，更不是 Launcher 首帧时间。它的消费者通常是启动性能工具，而真正的屏幕和输入状态由 WMS/ATMS 后续更新。

3. 启动终点

一次启动至少有三个相邻但不同的终点：屏幕启用请求、BootPhase 1000、sys.boot_completed=1。它们由 ensureBootCompleted() 和 finishBooting() 串联，但 boot animation 是一个条件屏障。

源码文件：frameworks/base/services/core/java/com/android/server/am/ActivityManagerService.java

java

final void ensureBootCompleted() {
    boolean booting;
    boolean enableScreen;
    synchronized (mGlobalLock) {
        booting = mBooting;
        mBooting = false;
        enableScreen = !mBooted;
        mBooted = true;
    }
    if (booting) {
        finishBooting();
    }
    if (enableScreen) {
        mAtmInternal.enableScreenAfterBoot(mBooted);
    }
}

mBooting 和 mBooted 由 AMS 持有，分别控制 finishBooting() 是否调用以及屏幕是否只启用一次。即使 finishBooting() 因 boot animation 未完成而提前返回，enableScreenAfterBoot() 仍可能执行，因此 boot_progress_enable_screen 可以早于最终 boot completed。

java

final void finishBooting() {
    synchronized (mGlobalLock) {
        if (!mBootAnimationComplete) {
            mCallFinishBooting = true;
            return;
        }
        mCallFinishBooting = false;
    }

    ZYGOTE_PROCESS.bootCompleted();
    VMRuntime.bootCompleted();
    ...
    mSystemServiceManager.startBootPhase(
            t, SystemService.PHASE_BOOT_COMPLETED);
    ...
    SystemProperties.set("sys.boot_completed", "1");
    SystemProperties.set("dev.bootcomplete", "1");
    mUserController.onBootComplete(...);
}

public void bootAnimationComplete() {
    final boolean callFinishBooting;
    synchronized (mGlobalLock) {
        callFinishBooting = mCallFinishBooting;
        mBootAnimationComplete = true;
    }
    if (callFinishBooting) {
        finishBooting();
    }
}

正常路径中，boot animation 完成后才允许 PHASE_BOOT_COMPLETED 和属性写入。checkpoint commit 失败还会直接请求重启；factory test low-level 分支会在属性写入前返回。于是“SystemService 收到 phase 1000”“init 收到属性触发器”“用户收到 BOOT_COMPLETED 广播”也不能视为同一瞬间。

4. 重复测量

单次启动受温度、文件页缓存、首次启动/升级、后台安装和设备配置影响。AOSP 自带的 system/core/init/perfboot.py 会重启多次、等待结束事件，并输出每个 tag 的 TSV、均值、中位数和标准差。

源码文件：system/core/init/perfboot.py

python

_DEFAULT_EVENT_TAGS = [
    'boot_progress_start',
    'boot_progress_preload_start',
    'boot_progress_preload_end',
    'boot_progress_system_run',
    'boot_progress_pms_start',
    'boot_progress_pms_system_scan_start',
    'boot_progress_pms_data_scan_start',
    'boot_progress_pms_scan_end',
    'boot_progress_pms_ready',
    'boot_progress_ams_ready',
    'boot_progress_enable_screen',
    'sf_stop_bootanim',
    'wm_boot_animation_done',
]

record[(tag, pid)] = event_time
if tag == end_tag:
    booted = True

记录键包含 (tag, pid)，正是为了保留双 Zygote 的同名事件。默认结束点是列表最后的 wm_boot_animation_done，不是 enable_screen。若实验目标是 Framework ready，可以显式选另一个 --end-tag，但基线与实验必须相同。

bash

# 运行位置：AOSP 根目录。输入为同一设备的多次冷启动，输出为 TSV。
# 固定 120 秒间隔可减少连续重启导致的温度差异。
system/core/init/perfboot.py \
  --iterations 10 \
  --interval 120 \
  --end-tag wm_boot_animation_done \
  --output boot-baseline.tsv

# 修改后使用相同设备、构建类型、终点、迭代数和间隔。
system/core/init/perfboot.py \
  --iterations 10 \
  --interval 120 \
  --end-tag wm_boot_animation_done \
  --output boot-experiment.tsv

脚本默认会检查 dm-verity 设置，并尝试根据 CPU 温度安排间隔；这说明“等设备在线就立即重启”不是可靠对照实验。还要注意当前 tag 中脚本声明为 Python 3，但 median() 使用 n / 2 作为列表下标；奇数样本数可能在汇总阶段触发类型错误。使用前应在本地副本把索引改为整数除法 n // 2，不要因此丢弃已经写入的 TSV 原始记录。

如果只需检查一次事件流，可以直接读取 events buffer，但仍应解析 payload。

bash

# 输入：一次刚完成的启动。输出：带生产者 PID 的启动事件和 monotonic payload。
adb logcat -b events -v threadtime -d \
  | rg 'boot_progress_|sf_stop_bootanim|wm_boot_animation_done'

# 输入：system_server 当前状态。输出：启动次数及两种时钟锚点。
adb shell dumpsys system_server_dumper \
  | rg 'Runtime restart|Start count|Runtime start'

如果 start_count > 1，说明当前 system_server 是 runtime restart；这类数据不应混入冷启动分布。事件缺失时也不能用相邻 tag 猜值，应把该轮标记为无效并检查 producer 是否走到对应分支。

5. SystemServer切片

EventLog 只能告诉你 system_run → pms_ready → ams_ready 哪个区间变长。进入 SystemServer 后，TimingsTraceAndSlog 用嵌套 section 继续拆分；更细的服务构造、onStart()、BootPhase 和线程池等待见服务启动耗时。

源码文件：

frameworks/base/services/core/java/com/android/server/utils/TimingsTraceAndSlog.java
frameworks/base/core/java/android/util/TimingsTraceLog.java

java

public void traceBegin(String name) {
    assertSameThread();
    Trace.traceBegin(mTraceTag, name);
    if (!DEBUG_BOOT_TIME) return;
    ...
    mStartNames[mCurrentLevel] = name;
    mStartTimes[mCurrentLevel] = SystemClock.elapsedRealtime();
}

public void traceEnd() {
    assertSameThread();
    Trace.traceEnd(mTraceTag);
    if (!DEBUG_BOOT_TIME) return;
    ...
    long duration = SystemClock.elapsedRealtime()
            - mStartTimes[mCurrentLevel];
    logDuration(name, duration);
}

Trace.traceBegin/End 总会调用；Java duration 栈只在 !Build.IS_USER 时启用。对象还记录创建线程 ID，跨线程复用会抛 IllegalStateException，所以异步任务必须创建自己的 TimingsTraceAndSlog.newAsyncLog()。owner 是创建它的线程，而不是整个 SystemServer 进程。

TimingsTraceAndSlog.traceBegin() 额外写 Slog.d，logDuration() 写 verbose duration。user build 中不能假定 logcat 一定包含完整的 took to complete；Perfetto 的 system_server trace section 更适合保留嵌套和调度上下文。

bash

# 输入：一次启动期间的 system_server 日志；输出：阶段入口和非 user build duration。
adb logcat -b system -v threadtime -d \
  'SystemServerTiming:*' 'SystemServerTimingAsync:*' '*:S'

# 输入：源码树；输出：EventLog 大区间对应的 trace section 和等待点。
rg -n 'traceBegin\(|waitForFutureNoInterrupt|StartPackageManagerService|PhaseActivityManagerReady' \
  frameworks/base/services/java/com/android/server/SystemServer.java \
  frameworks/base/services/core/java/com/android/server/am/ActivityManagerService.java

6. Bootchart采样

Bootchart 的 owner 是 init 进程中的 g_bootcharting_thread。默认 init.rc 在 early-init 和 post-fs-data 都调用 bootchart start，但只有内核参数 androidboot.bootchart.enabled=1 或 /data/bootchart/enabled 存在时才真正启动。

源码文件：

system/core/init/bootchart.cpp
system/core/rootdir/init.rc

cpp

static bool is_bootchart_enabled() {
    if (GetBoolProperty("ro.boot.bootchart.enabled", false)) {
        return true;
    }
    // File content is ignored; only existence matters.
    std::string start;
    return ReadFileToString("/data/bootchart/enabled", &start);
}

static Result<void> do_bootchart_start() {
    if (!is_bootchart_enabled()) return {};
    if (!g_bootcharting_thread) {
        g_bootcharting_thread.emplace(bootchart_thread_main);
    }
    return {};
}

/data/bootchart/enabled 的内容不会被解析为采集秒数。early-init 模式写 /dev/bootchart/，文件模式在 data 挂载后写 /data/bootchart/；第二次 start 看到线程已存在时不会重复创建。

cpp

while (true) {
    std::unique_lock<std::mutex> lock(g_bootcharting_finished_mutex);
    g_bootcharting_finished_cv.wait_for(lock, 200ms);
    if (g_bootcharting_finished) break;

    log_file(stat_log, "/proc/stat");
    log_file(disk_log, "/proc/diskstats");
    log_processes(proc_log);
}

采样周期是 200ms。proc_ps.log 保存每个 PID 的 /proc/<pid>/stat，并用 /proc/<pid>/cmdline 替换截断的进程名；proc_stat.log 和 proc_diskstats.log 分别提供 CPU 与块设备视角。小于一个采样周期的短进程可能完全看不到，进程启动时间的比较精度也不能当成方法级 trace。

停止路径由 init 属性触发器消费：

text

on property:sys.boot_completed=1
    bootchart stop

do_bootchart_stop() 设置 g_bootcharting_finished、唤醒线程并 join()，所以日志文件在 stop 返回前完成收尾。线程创建后若 mount namespace unshare 或日志文件打开失败，只会记录错误并退出；bootchart start 本身是异步的，不会把失败同步传播成 Android 启动失败。

设备需要 root 才能创建启用文件和拉取完整数据。AOSP 的抓取脚本还依赖 pybootchartgui 与 xdg-open，运行环境不满足时可以只保留 tarball。

bash

# 输入：可adb root的测试设备。enabled文件内容无意义，只需存在。
adb root
adb shell mkdir -p /data/bootchart
adb shell touch /data/bootchart/enabled
adb reboot
adb wait-for-device
adb shell 'while [ "$(getprop sys.boot_completed)" != 1 ]; do sleep 1; done'

# 输出：header、CPU、磁盘和进程日志组成的bootchart.tgz。
system/core/init/grab-bootchart.sh

# 输入：两个目录内各有bootchart.tgz；输出：关键进程起点和bootanimation终点差值。
system/core/init/compare-bootcharts.py boot-base boot-experiment

compare-bootcharts.py 从前两个 200ms timestamp 推导 jiffy 到毫秒的换算，比较 init、SurfaceFlinger、bootanimation、Zygote 和 system_server。它把 bootanimation 最后一次出现当作用户感知终点的粗略代理，不等于 Launcher 首帧。

7. 联合定位

下面的判断顺序比“看到某个大数就优化对应类”更可靠：

现象	先看	再看	可能的 owner
preload 区间回归	按 PID 配对 preload 事件	Zygote trace、类/资源预加载日志	primary 或 secondary Zygote
`system_run → pms_start` 变长	SystemServer 顶层 trace	默认显示等待、bootstrap service、调度状态	SystemServer 主线程或依赖服务
PMS scan 区间变长	三个 scan 事件	Bootchart 磁盘、PMS trace、首次启动条件	PMS executor、存储或包集合
`pms_ready → ams_ready` 变长	SystemServer/AMS trace	异步 Future、WMS/PMS ready 回调	SystemServer 主线程与异步任务
enable screen 变快但 animation 不变	两个不同终点	SurfaceFlinger/WMS/Launcher trace	显示链或 Home 绘制，而非 AMS ready
bootchart CPU 空闲但终点变慢	EventLog + Perfetto	Binder、锁、I/O wait、Future	等待方及其真正消费者

一项改动如果只让 TotalBootTime 变短，却让 wm_boot_animation_done 或 Launcher 首帧变慢，就是把工作移出了局部指标，而不是改善用户体验。反过来，预加载增加可能让 Zygote 阶段变慢，却减少后续每个应用的缺页和类初始化；结论必须由本文定义的目标决定。

8. 验证边界

源码测试：frameworks/base/core/tests/mockingcoretests/src/android/util/TimingsTraceLogTest.java 构造同线程和跨线程调用，断言嵌套 Trace.traceBegin/End 数量、duration 日志以及错误的 traceEnd() warning。它证明 timing 对象具有线程所有权和严格嵌套边界，但不证明真实启动中某个 section 一定出现。

源码文件：frameworks/base/core/tests/mockingcoretests/src/android/util/TimingsTraceLogTest.java

java

TimingsTraceLog log = new TimingsTraceLog(TAG, TRACE_TAG_APP, 10);
log.traceBegin("L1");
log.traceBegin("L2");
log.traceEnd();
log.traceEnd();

verify((MockedVoidMethod) () ->
        Trace.traceEnd(TRACE_TAG_APP), times(2));
verify((MockedVoidMethod) () -> Slog.v(eq(TAG),
        matches("L2 took to complete: \\d+ms")));
verify((MockedVoidMethod) () -> Slog.v(eq(TAG),
        matches("L1 took to complete: \\d+ms")));

源码测试：frameworks/base/services/tests/PackageManagerServiceTests/host/src/com/android/server/pm/test/BootTest.kt 在设备 reboot 后最多轮询 45 秒，只有 getprop sys.boot_completed 返回 1 才认为 Framework ready。这个断言验证的是属性消费者的等待契约，不包含屏幕、Launcher 首帧或所有 BOOT_COMPLETED receiver 已执行完毕。

源码文件：frameworks/base/services/tests/PackageManagerServiceTests/host/src/com/android/server/pm/test/BootTest.kt

kotlin

private fun waitForBootCompleted() {
    for (i in 0 until 45) {
        if (isBootCompleted()) {
            return
        }
        Thread.sleep(1000)
    }
    throw AssertionError("System failed to become ready!")
}

private fun isBootCompleted(): Boolean {
    return "1" == device.executeShellCommand(
            "getprop sys.boot_completed").trim()
}

排查一次真实回归时，可以用两个问题检查自己是否真正读通了源码：第一，给出 boot_progress_enable_screen 领先但 wm_boot_animation_done 不变的日志，能否指出前者的写入时机和后者仍需检查的消费者；第二，给出双 Zygote 的四条 preload 事件，能否按 PID 配对并说明为什么不能与 BOOT_PROGRESS_SYSTEM_RUN 直接跨时钟相减。只有能回答这两点，时间线才从“日志列表”变成了可用于修改源码的因果模型。

启动时间分析 ​

1. 三种时间源 ​

2. 事件里程碑 ​

2.1 Zygote预加载 ​

2.2 系统服务与PMS ​

2.3 AMS与屏幕 ​

3. 启动终点 ​

4. 重复测量 ​

5. SystemServer切片 ​

6. Bootchart采样 ​

7. 联合定位 ​

8. 验证边界 ​

启动时间分析

1. 三种时间源

2. 事件里程碑

2.1 Zygote预加载

2.2 系统服务与PMS

2.3 AMS与屏幕

3. 启动终点

4. 重复测量

5. SystemServer切片

6. Bootchart采样

7. 联合定位

8. 验证边界