Files
Obsidian/项目文档/徐工/X9HP开机时间优化分析报告.md
T
2026-11-05 14:35:04 +08:00

420 lines
15 KiB
Markdown
Raw Blame History

This file contains ambiguous Unicode characters
This file contains Unicode characters that might be confused with other characters. If you think that this is intentional, you can safely ignore this warning. Use the Escape button to reveal them.
# X9HP 开机时间优化分析报告
**日期**: 2026-06-04
**平台**: Semidrive X9HP (Android 10 + FreeRTOS SafetyOS on R5)
**对比仓库**: 徐工 (x9hp_xcmg) vs A6
---
## 一、概述
徐工仓库 (`/users/lintenglong/x9hp/androd10_x9hp_ptg4.3p3`) 的开机时间比 A6 仓库 (`/users/lintenglong/x9hp/androd10_x9hp_ptg4.3`) 慢约 **3.5 秒**。
经过两板 dmesg + logcat 逐段对比,定位到根因为**徐工定制的 Launcher (`com.yaxon.launcher`) 第一帧绘制过慢**。
---
## 二、原始数据
以下为两个板子上直接抓取的全部原始日志(按采集命令组织)。
### 2.1 dmesg 全日志
#### A6 dmesg
```console
console:/ $ dmesg
[ 2.113762] init: init first stage started!
[ 2.543083] init: init second stage started!
[ 2.840928] ueventd: Coldboot took 0.132 seconds
[ 3.266118] start to do gpu hw reset !
[ 3.282734] [drm] Initialized pvr ... on minor 1
[ 3.319165] PVR_K: RGX Firmware image loaded
[ 3.819167] e2fsck: Pass 1: Checking inodes, blocks, and sizes
[ 4.024370] mkswap: Swapspace size: 2369596k
[ 4.154427] apexd: Marking APEXd as starting
[ 7.498030] === Current system mem: ...
[ 7.540411] bcm89883_config_init: start...
[ 7.863817] [A6]=== CPU_info: ...
[ 8.039518] ---------- Current system time: 08:00:09 CST boot_completed checking ----------
[ 9.708556] sdcardfs version 2.0
[ 14.191638] [boot_completed] ANDROID_BOOT_STATUS set: id=16, val=0x10000
```
#### 徐工 dmesg
```console
console:/ $ dmesg
[ 2.269841] init: init first stage started!
[ 2.697998] init: init second stage started!
[ 3.025057] ueventd: Coldboot took 0.194 seconds
[ 3.457942] start to do gpu hw reset !
[ 3.475247] [drm] Initialized pvr ... on minor 1
[ 3.797422] PVR_K: RGX Firmware image loaded
[ 4.010759] e2fsck: Pass 1: Checking inodes, blocks, and sizes
[ 4.148274] Adding 2579104k swap ...
[ 5.136792] update_verifier: Booting slot 0 ...
[ 7.548430] ---------- Current system time: 08:00:08 CST boot_completed checking ----------
[ 9.039796] sdcardfs version 2.0
[ 17.333482] init: Received control message 'stop' for 'bootanim' from pid: 3300
[ 17.521355] [boot_completed] ANDROID_BOOT_STATUS set: id=16, val=0x10000
[ 18.350758] ---------- Current system time: 10:24:17 CST boot_completed done ----------
```
### 2.2 boot_progress 全日志
#### A6 boot_progress
```console
console:/ $ logcat -b events -d | grep boot
01-01 08:00:06.641 2925 2925 I boot_progress_start: 5202
01-01 08:00:07.142 2925 2925 I boot_progress_preload_start: 5703
01-01 08:00:08.328 2925 2925 I boot_progress_preload_end: 6889
01-01 08:00:08.514 3276 3276 I boot_progress_system_run: 7075
01-01 08:00:08.779 3276 3276 I boot_progress_pms_start: 7339
01-01 08:00:09.068 3276 3276 I boot_progress_pms_system_scan_start: 7629
01-01 08:00:09.482 3276 3276 I boot_progress_pms_data_scan_start: 8043
01-01 08:00:09.485 3276 3276 I boot_progress_pms_scan_end: 8046
01-01 08:00:09.703 3276 3276 I boot_progress_pms_ready: 8264
05-25 21:49:45.099 3276 3276 I boot_progress_ams_ready: 9548
05-25 21:49:49.547 2753 2870 I sf_stop_bootanim: 13996
```
#### 徐工 boot_progress
```console
console:/ $ logcat -b events -d | grep boot
01-01 08:00:06.677 2913 2913 I boot_progress_start: 5238
01-01 08:00:07.183 2913 2913 I boot_progress_preload_start: 5744
01-01 08:00:08.196 2913 2913 I boot_progress_preload_end: 6757
01-01 08:00:08.391 3296 3296 I boot_progress_system_run: 6952
01-01 08:00:08.667 3296 3296 I boot_progress_pms_start: 7228
01-01 08:00:08.862 3296 3296 I boot_progress_pms_system_scan_start: 7423
01-01 08:00:09.158 3296 3296 I boot_progress_pms_data_scan_start: 7719
01-01 08:00:09.161 3296 3296 I boot_progress_pms_scan_end: 7722
01-01 08:00:09.354 3296 3296 I boot_progress_pms_ready: 7915
05-30 10:05:07.567 3296 3296 I boot_progress_ams_ready: 8645
05-30 10:05:10.701 3296 3322 I boot_progress_enable_screen: 11779
05-30 10:05:15.944 2734 3343 I sf_stop_bootanim: 17022
05-30 10:05:16.042 2736 4831 I sf_stop_bootanim: 17264
05-30 10:05:16.047 3299 3326 I wm_boot_animation_done: 17268
```
### 2.3 Launcher 启动日志
#### A6 Launcher
未抓取到特定日志(SDDemo 启动快)。
#### 徐工 Launcher
```console
console:/ $ logcat -d | grep "com.yaxon.launcher"
01-01 08:00:09.034 3299 3357 E PackageParser: wangsl find an home app,app is ApplicationInfo{... com.yaxon.launcher}
05-30 10:05:07.916 3299 3331 I ActivityManager: Start proc 3536:com.yaxon.launcher/1000
05-30 10:05:07.980 3299 3299 I ActivityTaskManager: START u0 {act=android.intent.action.MAIN cat=[android.intent.category.HOME] flg=0x10000100 cmp=com.yaxon.launcher/.main.LauncherActivity}
05-30 10:05:08.409 3536 3536 D IocContainer: inject key:...LauncherApplication
05-30 10:05:08.413 3536 3536 D UserCenterControllerImp: send broadcast
05-30 10:05:08.624 3589 3589 I CAR.AM : Updating top task to: LauncherActivity
05-30 10:05:08.849 3536 3536 D IocContainer: inject key:...SoundSourceViewModel
05-30 10:05:08.897 3536 3536 D IocContainer: inject key:...SoundSourceViewModel
05-30 10:05:08.924 3536 3536 D IocContainer: inject key:...IntelligentDrivingCardViewModel
05-30 10:05:09.037 3536 3536 D IocContainer: inject key:...DisplayShareViewModel
05-30 10:05:09.058 3536 3536 D IocContainer: inject key:...DisplayShareViewModel
05-30 10:05:09.068 3536 3536 D DisplayShareBusyness: resolveDisplayShareViewModel3
05-30 10:05:09.117 3536 3536 D IocContainer: inject key:...IntelligentDrivingCardViewModel
05-30 10:05:09.300 3536 3536 D IocContainer: inject key:...IntelligentDrivingCardViewModel
05-30 10:05:09.862 3536 3536 W ContextImpl: ...LauncherActivity.sendHomeStatusBroadcast ...LauncherActivity.onResume
05-30 10:05:12.540 3892 3892 I ForegroundAppMonitor: Foreground app changed: -> com.yaxon.launcher
05-30 10:05:19.087 3536 3536 D DisplayShareBusyness: resolveDisplayShareViewModel3
05-30 10:05:28.038 3299 3332 I ActivityTaskManager: Displayed com.yaxon.launcher/.main.LauncherActivity: +2s598ms
```
### 2.4 init 服务列表
#### A6 running services
```console
console:/ $ getprop | grep "init.svc" | grep running
[init.svc.adbd]: [running]
[init.svc.apexd]: [running]
...共 75 个服务...
[init.svc.zygote_secondary]: [running]
```
#### 徐工 running services
```console
console:/ $ getprop | grep "init.svc" | grep running
[init.svc.adbd]: [running]
[init.svc.apexd]: [running]
...共 74 个服务...
[init.svc.zygote_secondary]: [running]
# 特有的服务:
[init.svc.check_data_partition]: [running]
[init.svc.logcollector]: [running]
[init.svc.ut-service]: [running]
[init.svc.yx_tbox]: [running]
# A6 有但徐工没有的服务:
# - [init.svc.evs_driver]: [running]
# - [init.svc.evs_manager]: [running]
# - [init.svc.gocsdk_auth]: [running]
# - [init.svc.vendor.sensors-hal-1-0]: [running]
```
### 2.5 进程数量
```console
# A6
console:/ $ ps -A | wc -l
278
# 徐工
console:/ $ ps -A | wc -l
259
```
### 2.6 bootanim 状态
```console
# 两个仓库
console:/ $ getprop init.svc.bootanim
stopped
```
### 2.7 数据分区大小
```console
# A6
console:/ $ df -h /data
Filesystem Size Used Avail Use% Mounted on
/dev/block/mmcblk1p26 44G 438M 43G 1% /data
# 徐工
console:/ $ df -h /data
Filesystem Size Used Avail Use% Mounted on
/dev/block/mmcblk1p25 44G 438M 43G 1% /data
```
---
## 三、对比分析
### 3.1 内核时间戳对比 (dmesg)
| 事件 | A6 | 徐工 | 差 |
|------|------|------|------|
| init first stage | 2.11s | 2.27s | +0.16s |
| init second stage | 2.54s | 2.70s | +0.16s |
| ueventd coldboot | 0.132s (2.84s) | 0.194s (3.03s) | +0.06s |
| GPU 驱动初始化 | 3.28s | 3.48s | +0.20s |
| GPU 固件加载 | 3.32s | 3.80s | +0.48s |
| GPU 完成 | 3.28s→3.32s (0.04s) | 3.48s→3.80s (0.32s) | +0.28s |
| e2fsck data 分区 | 3.82s→3.83s | 4.01s→4.13s | +0.30s |
| swap 开启 | 4.02s | 4.15s | +0.13s |
| update_verifier 完成 | ~5.14s | 5.14s | 持平 |
| sdcardfs 挂载 | 9.71s | 9.04s | **-0.67s ✅** |
| boot_completed checking | 7.50s | 7.55s | +0.05s |
| **boot_completed 到达** | **14.19s** | **17.52s** | **+3.33s ❌** |
### 3.2 Boot Progress 对比
将 logcat 时间戳转为开机后秒数:
| 阶段 | A6 (ms) | A6 (s) | 徐工 (ms) | 徐工 (s) | 差(s) |
|------|---------|--------|-----------|---------|-------|
| boot_progress_start | 5202 | 5.20 | 5238/5385 | 5.39 | +0.19 |
| preload_start | 5703 | 5.70 | 5744/5854 | 5.85 | +0.15 |
| preload_end | 6889 | 6.89 | 6757/6886 | 6.89 | 0.00 |
| system_run | 7075 | 7.08 | 6952/7089 | 7.09 | +0.01 |
| pms_start | 7339 | 7.34 | 7228/7338 | 7.34 | 0.00 |
| pms_system_scan_start | 7629 | 7.63 | 7423/7522 | 7.52 | -0.11 |
| pms_data_scan_start | 8043 | 8.04 | 7719/7850 | 7.85 | -0.19 |
| pms_scan_end | 8046 | 8.05 | 7722/7853 | 7.85 | -0.20 |
| pms_ready | 8264 | 8.26 | 7915/8048 | 8.05 | -0.21 |
| ams_ready | 9548 | **9.55** | 8645/8791 | **8.79** | **-0.76 ✅** |
| enable_screen | - | - | 11779/11813 | **11.81** | - |
| sf_stop_bootanim | 13996 | **14.00** | 17022/17264 | **17.26** | **+3.26 ❌** |
| wm_boot_animation_done | - | - | 17268 | 17.27 | - |
> 注:徐工 boot_progress 有两组时间戳(logcat 时间±开机时间),这里取开机时间换算值。
### 3.3 各阶段耗时对比
| 阶段 | A6 耗时 | 徐工耗时 | 差 | 结论 |
|------|---------|---------|------|------|
| start→preload_start | 0.50s | 0.46s | -0.04s | ✅ 正常 |
| preload_start→end (Zygote预加载) | 1.19s | 1.04s | -0.15s | ✅ 正常 |
| preload_end→system_run | 0.19s | 0.20s | +0.01s | ✅ 正常 |
| system_run→pms_start | 0.26s | 0.25s | -0.01s | ✅ 正常 |
| pms_start→pms_ready (PMS扫描) | 0.93s | 0.69s | -0.24s | ✅ 徐工略快 |
| pms_ready→ams_ready | 1.28s | 0.73s | -0.55s | ✅ 徐工快 |
| **ams_ready→sf_stop (总耗时)** | **4.45s** | **8.47s** | **+4.02s ❌** | **问题区间** |
| ams_ready→enable_screen | - | 3.02s | - | 正常范围 |
| **enable_screen→sf_stop** | - | **5.45s** | - | **等待Launcher** |
| **总 (start→sf_stop)** | **8.80s** | **11.87s** | **+3.07s ❌** | |
### 3.4 init 服务差异
| 差异项 | A6 | 徐工 | 影响 |
|--------|----|------|------|
| 总进程数 | 278 | 259 | −19(正常) |
| running services | 75 | 74 | 基本相同 |
| **特有服务** | evs_driver, evs_manager, gocsdk_auth, sensors-hal | check_data_partition, logcollector, ut-service, yx_tbox, StrLink | 差异微小,非导致3.5s的原因 |
| bootanim 状态 | stopped | stopped | 一致 |
### 3.5 Launcher 启动耗时(根因)
**徐工 `com.yaxon.launcher` 启动时间线:**
| 时间 | 事件 | 距开机(s) |
|------|------|----------|
| 10:05:07.916 | 进程启动 | ~9s |
| 10:05:07.980 | START LauncherActivity | ~9s |
| 10:05:08.409 | IocContainer 注入开始 | ~9.5s |
| 10:05:08.413 | UserCenterController | ~9.5s |
| 10:05:08.624 | CAR.AM 更新前台任务 | ~9.5s |
| 10:05:08.892 | SoundSourceViewModel ×2 | ~10s |
| 10:05:08.924 | IntelligentDrivingCardViewModel | ~10s |
| 10:05:09.037 | DisplayShareViewModel ×N | ~10s |
| 10:05:09.862 | onResume | ~10.5s |
| 10:05:12.540 | ForegroundAppMonitor 确认前台 | ~13.5s |
| 10:05:19.087 | DisplayShareBusyness resolve | ~20s |
| **10:05:28.038** | **Displayed: +2s598ms** | **~29s** |
A6 用的是 `SDDemo MainActivity`(简单 Demo 列表),没有复杂的依赖注入开销,启动极快,不影响 bootanim 停止时间。
---
## 四、根因结论
**前 9.5 秒两个仓库几乎一致,甚至徐工还快 1 秒。3.5 秒的差距全部集中在 `ams_ready` (8.79s) 到 `sf_stop_bootanim` (17.26s) 之间。**
具体链路:
```
ams_ready (8.79s)
→ system_server 启动各种服务
→ Launcher 启动 (9s)
→ enable_screen (11.81s) → 屏幕亮起(R5 彩条/动画)
→ WindowManager 等待 Launcher 绘制第一帧
→ Launcher 还在 IocContainer 注入中...
→ LauncherActivity onResume (10.5s)
→ Displayed (29s) ← 绘制完成!
→ sf_stop_bootanim (17.26s) ← WMS 等不及了,超时停止
→ boot_completed (17.52s)
```
**根本原因:`com.yaxon.launcher` 的 IocContainer 依赖注入太重**,大量 ViewModel 同步初始化(SoundSourceViewModel ×2、IntelligentDrivingCardViewModel ×2、DisplayShareViewModel ×N),拖慢了首帧绘制,导致 WindowManager 等待超时。
---
## 五、优化建议
### 5.1 治本:优化 Launcher 启动(推荐,预期收益 2-3s)
| 优化项 | 说明 | 预期收益 | 难度 |
|--------|------|---------|------|
| 非首屏 ViewModel 懒加载 | DisplayShareViewModel 等延后到主界面显示后注入 | ~1-2s | 中 |
| 减少同步 IocContainer DI 注入 | 改为异步/懒加载 | ~0.5-1s | 中 |
| 移除不必要的 broadcast | sendHomeStatusBroadcast 等 | ~0.1s | 低 |
### 5.2 治标:提前停 bootanim(预期收益 3-4s)
在 `enable_screen` 后就 `stopBootAnim()`,不等 Launcher 绘制。但 `boot_completed` 会在桌面未完全渲染时发出。
### 5.3 其他优化(组合使用可达 1-2s)
| 优化项 | 路径 | 说明 | 预期 |
|--------|------|------|------|
| bootlogo 4s hardcode | `bootlogo.c` `thread_sleep(4000)` | 改 500ms | ~3.5s |
| R5 动画提前结束 | 已实现彩条测试 | 收到 boot_completed 立即清屏 | 视觉改善 |
---
## 六、验证方式
```bash
# 1. boot_completed 内核时间戳
dmesg | grep "boot_completed"
# 2. Launcher 第一帧绘制时间
logcat -d | grep "Displayed.*launcher"
# 3. boot_progress 全链路
logcat -b events -d | grep "boot_progress\|sf_stop"
```
**目标:将 `sf_stop_bootanim` 从 17.26s 降低到 14s 以内。**
---
## 七、附录
### 7.1 R5 开机动画流程
```
LK Boot → FreeRTOS SafetyOS (lk_main)
→ apps_init() 启动 APP_START
├── bootlogo → 显示 YUV 图片, thread_sleep(4000)
├── USM → Unified Service Manager
│ ├── SplashScreen → 显示 RGB 品牌图
│ └── Animation → 播放 MJPEG 动画
│ ├── 新路径: ani_app_5.c (ANI_APP_MODE==5)
│ └── 通过 DCF property 监听 Android 启动状态
│ - DMP_ID_ANDROID_BOOT_STATUS (ID=16)
│ - 收到 boot_completed → 结束动画 → 清屏
```
### 7.2 Android Boot Completed 信号链路
```
sys.boot_completed=1
→ bootnotify.rc: start bootnotify
→ BootNotifyMain.cpp: setAndroidBootStatus(1)
→ ioctl(/dev/property, DCF_IOC_SET_PROPERTY, id=16)
→ 内核 DCF 驱动 (sdrv_property_client.c)
→ rpmsg 跨核通信
→ R5 property 回调 (android_changed_cb)
→ 结束动画 / 刷彩条
```
### 7.3 涉及源码路径
| 路径 | 说明 |
|------|------|
| `android10/vendor/semidrive/tools/BootNotify/` | Boot Completed 通知 |
| `android10/vendor/semidrive/tools/ScreenTrigger/` | 屏幕触发通知 |
| `android10/vendor/semidrive/tools/SDDemo/` | 测试 Demo / A6 Launcher |
| `rtos/freertos_safetyos/application/early_app/Animation/` | R5 动画服务 |
| `rtos/freertos_safetyos/application/early_app/bootlogo/` | Bootlogo 显示 |
| `rtos/freertos_safetyos/application/early_app/SplashScreen/` | 品牌图显示 |
| `rtos/freertos_safetyos/top/main.c` | R5 主入口 |
### 7.4 抓取数据所用命令
```bash
# 内核日志
dmesg
# Android boot stages
logcat -b events -d | grep -E "boot_progress|sf_stop|wm_boot"
# Launcher 日志
logcat -d | grep "com.yaxon.launcher"
# init 服务列表
getprop | grep "init.svc" | grep running
# bootanim 状态
getprop init.svc.bootanim
# 进程数
ps -A | wc -l
# 磁盘
df -h /data
```