12、Logcat 在系统服务中的应用:AMS、WMS、PMS 的日志解读

系统服务是 Android 的骨架。AMS、WMS、PMS 这三个,可以说是骨架里最粗的三根骨头。

做系统开发这些年,我有个习惯——遇到诡异问题,第一反应不是翻源码,而是先拉 Logcat。为什么?因为源码不会告诉你运行时发生了什么,但日志会。AMS 的日志告诉你 Activity 为什么没启动,WMS 的日志告诉你窗口为什么没显示,PMS 的日志告诉你应用为什么装不上。

说白了,读懂这三个服务的日志,你就掌握了 Android 系统排障的半壁江山。

12.1 AMS 日志解读:Activity 的生死簿

AMS(ActivityManagerService)负责管理 Activity 的生命周期、任务栈、进程调度。它的日志量非常大,但关键信息就那么几类。

12.1.1 Activity 启动流程日志

启动一个 Activity 时,AMS 会输出大量日志。我一般会先过滤 ActivityManager 这个 tag。

// 启动请求到达 AMS
I ActivityManager: START u0 {act=android.intent.action.MAIN cat=[android.intent.category.LAUNCHER] flg=0x10200000 cmp=com.example/.MainActivity} from uid 1000

// AMS 检查权限和进程状态
I ActivityManager: Start proc 12345:com.example/u0a123 for activity {com.example/.MainActivity}

// Activity 创建完成
I ActivityManager: Displayed com.example/.MainActivity: +1s234ms

这里有个关键点:Displayed 时间。它表示从 AMS 收到启动请求到 Activity 第一帧绘制完成的时间。如果这个时间超过 5 秒,系统就会弹 ANR 对话框。

我的经验: 我曾经遇到一个启动黑屏问题,Displayed 时间显示 3 秒,但用户感觉等了 5 秒。后来发现是 onCreate 里做了太多初始化,但 AMS 只统计到 onResume 完成。所以 Displayed 时间正常,不代表用户体验正常。

12.1.2 进程优先级与杀进程日志

AMS 负责决定什么时候杀进程。日志里经常能看到这样的信息:

I ActivityManager: Killing 12345:com.example/u0a123 (adj 15): empty #17
W ActivityManager: Scheduling restart of crashed service com.example/.MyService in 1000ms

adj 是进程的优先级,数值越大越容易被杀。adj 15 是空进程,系统内存不足时优先清理。

注意: 如果你的应用后台服务经常被杀,检查日志里是不是频繁出现 adj 15adj 9。adj 9 是缓存进程,adj 15 是空进程。想保活?先把 adj 值降到 5 以下再说。

12.1.3 ANR 日志定位

ANR 发生时,AMS 会输出非常详细的堆栈信息:

I ActivityManager: ANR in com.example (com.example/.MainActivity)
I ActivityManager: Reason: Input dispatching timed out (Waiting to send key event because the focused window has not finished processing all of the input events that were previously delivered to it.  Outbound queue length: 0.  Wait queue length: 1.)
I ActivityManager: Load: 2.35 / 1.98 / 1.72
I ActivityManager: CPU usage from 0ms to 5000ms later:
I ActivityManager:   40% 12345/com.example: 30% user + 10% kernel / faults: 1234 minor 56 major
I ActivityManager:   ...

看 ANR 日志,我习惯先看 Reason 字段。它告诉你是什么原因导致的超时。最常见的是输入事件分发超时,也就是主线程被卡住了。

然后看 CPU usage。如果 CPU 占用率很高,说明是计算密集型任务阻塞了主线程。如果 CPU 占用率很低,那可能是死锁或等待 I/O。

12.2 WMS 日志解读:窗口的调度密码

WMS(WindowManagerService)管理窗口的层级、布局、输入事件分发。它的日志 tag 是 WindowManager

12.2.1 窗口添加与显示

I WindowManager: Adding window Window{... u0 com.example/com.example.MainActivity} at 0 of 10 (after Window{...})
I WindowManager: Resizing window: Window{...} to (1080, 1920) state=0
I WindowManager: WindowStateAnimator: finishDrawingLocked: Window{...} in 0ms

窗口添加时,WMS 会输出窗口的层级位置。at 0 of 10 表示这个窗口在第 0 层,总共有 10 个窗口。层级越低,越靠近用户。

我记得有一次,一个悬浮窗死活显示不出来。看日志发现 Adding window 之后紧接着就是 Removing window。原来是权限检查失败,WMS 刚加上就移除了。

12.2.2 输入事件分发日志

I WindowManager: Input event dispatching to Window{...} took 120ms
W WindowManager: Input event dispatching timed out sending to Window{...}

输入事件分发超时是 WMS 最常见的警告之一。如果某个窗口处理输入事件超过 200ms,WMS 就会输出这个日志。

关键点: 输入事件分发超时 ≠ ANR。ANR 是 AMS 检测的,超时时间 5 秒。WMS 的输入超时是 200ms,只是警告,不会弹 ANR 对话框。但如果频繁出现,说明你的 UI 线程有卡顿。

12.2.3 窗口焦点变化

I WindowManager: Focus changed from Window{...} to Window{...}
I WindowManager: Gaining focus: Window{...}
I WindowManager: Losing focus: Window{...}

窗口焦点变化日志,可以用来排查触摸事件没响应的问题。如果焦点没有切换到你的窗口,那触摸事件自然就收不到。

12.3 PMS 日志解读:应用的安装与权限

PMS(PackageManagerService)管理应用的安装、卸载、权限。它的日志 tag 是 PackageManager

12.3.1 应用安装流程

I PackageManager: Installing package com.example versionCode 1 targetSdk 34
I PackageManager: Package com.example codePath=/data/app/com.example-1
I PackageManager: Package com.example new state: installed

安装过程中,PMS 会做签名验证、权限检查、dex 优化。如果安装失败,日志里会有明确的错误原因:

E PackageManager: Package com.example has no signatures that match those in shared user android.uid.system
E PackageManager: Package com.example requires unavailable shared library com.google.android.maps; failing!

我遇到过最坑的一次,是系统应用签名不一致导致安装失败。日志里明确写了签名不匹配,但开发同事坚持说签名没问题。最后发现是打包脚本用了 debug 签名,而系统要求的是 platform 签名。

12.3.2 权限检查日志

D PackageManager: checkPermission: android.permission.CAMERA for uid 10123
I PackageManager: Permission android.permission.CAMERA granted to uid 10123
W PackageManager: Permission android.permission.CAMERA denied for uid 10123 (not granted)

权限检查日志默认是 debug 级别,需要开启 setprop log.tag.PackageManager DEBUG 才能看到。我建议在开发阶段开启这个日志,可以快速定位权限问题。

小技巧: 如果应用运行时提示权限不足,但 Manifest 里已经声明了,先看 PMS 日志。有时候是权限被系统策略拦截了,比如 Permission denied for uid 10123 (not granted)。这时候需要检查权限组是否被关闭,或者是否在 Settings 里被手动拒绝了。

12.3.3 应用更新与数据迁移

I PackageManager: Updating package com.example from versionCode 1 to 2
I PackageManager: Package com.example new state: updated
I PackageManager: Package com.example data migrated from /data/data/com.example to /data/data/com.example-1

应用更新时,PMS 会处理数据迁移。如果数据迁移失败,应用可能会启动异常。日志里会输出迁移路径和错误信息。

12.4 三个服务的日志联动分析

很多时候,一个问题需要同时看三个服务的日志。比如应用启动闪退:

  1. AMS 日志显示 Start proc 成功
  2. WMS 日志显示 Adding window 成功
  3. PMS 日志显示 Permission denied 某个关键权限

这时候就能定位到:应用启动了,窗口也创建了,但因为权限不足导致某个功能崩溃,最终被 AMS 杀掉。

我习惯用 logcat -b all 同时抓取所有 buffer,然后用 grep 过滤三个 tag。这样能保证日志的时间戳是同步的,方便做时序分析。

总结一下:
  • AMS 日志看 Activity 生命周期、进程优先级、ANR 原因
  • WMS 日志看窗口层级、输入事件分发、焦点变化
  • PMS 日志看安装流程、权限检查、数据迁移
三个服务的日志配合使用,能解决 90% 的系统层问题。
Logcat 系统服务日志分析框架 AMS WMS PMS Activity 启动 进程优先级 ANR 分析 窗口添加 输入事件 焦点变化 安装流程 权限检查 数据迁移 三个服务日志联动分析,定位系统层问题

嗯,这一章内容不少。但说白了,日志就是系统的「黑匣子」。你读懂了它,系统在你面前就是透明的。下次遇到问题,别急着翻源码,先拉 Logcat 看看这三个服务的日志,说不定答案就在那里。


公众号:蓝海资料掘金营,微信deep3321