Android性能监控：主循环性能统计LooperStatsSe
作者：飞起来_飞过来
简介
在Android性能监控和优化领域，一个会影响App性能表现的因素与Handler Message Looper机制有关。当Looper里面的Message处理不及时、或数量太多占用过多处理时间时，可能会出现卡顿感，并且不容易定位到卡顿的Message和慢方法。
Android本身提供了LooperStats机制来统计和监测Message的处理，并且可以通过LooperStatsService来统计和记录，方便调试和分析。
LooperStatsService详解
由SystemServer创建、Settings数据库变更触发启动
LooperStatsService是一个系统服务，由SystemServer在开机阶段启动。按照系统服务的接口要求，它是通过LooperStatsService.Lifecycle这个类被启动的。
启动流程主要是初始化LooperStats、LooperStatsService和SettingsObserver。
SettingsObserver在Settings数据库的值发生变化时回调，回调方法中根据特定格式来解析数据库的内容，根据解析的内容确定是否开始监控、监控频率等。
数据库是Settings.Global.looper_stats，对应的数据库格式如下：使用键值对（key=value）来表示一个参数和它的值，多个键值对之间用逗号分隔。参数包括：sampling_interval控制采样频率（毫秒，默认1000），track_screen_state控制是否跟踪屏幕状态（默认false）。
也就是说，执行如下adb指令，写入Settings数据库，就能让LooperStatsService开始采样监控App的主循环Looper：
settings put global looper_stats sampling_interval=100,track_screen_state=true,enabled=true
启动流程非常简单，先参数值初始化，然后将Observer设置到Looper。
也可以采用adb命令的方式来控制：
# cmd looper_stats
looper_stats commands:
enable: Enable collecting stats.
disable: Disable collecting stats.
sampling_interval: Change the sampling interval.
reset: Reset stats.
Looper Message Dispatch流程实现监控
我们知道Android的主线程的死循环被Looper封装，在Looper内部取出MessageQueue内排队的Message，根据Message.target和callback，将其派发到对应的处理方法中，实现消息循环。实现监控的流程也很容易，在消息派发前回调到监控者，消息由处理函数处理完成后，回调监控者，即可实现让监控着感知消息处理的进度。
Looper本身提供了内部接口类Observer提供回调接口来实现上述需求：
public interface Observer {
Object messageDispatchStarting();
void messageDispatched(Object token, Message msg);
void dispatchingThrewException(Object token, Message msg, Exception exception);
}
前两个接口分别在一个消息处理前、一个消息完成处理时回调。第三个接口是Message处理过程中抛出了异常时回调。
App主事件循环实际上可以抽象为如下流程：
public static void loop() {
final Looper me = myLooper();
final MessageQueue queue = me.mQueue;
boolean slowDeliveryDetected = false;
for (;;) {
Message msg = queue.next(); // might block
if (msg == null) {
// No message indicates that the message queue is quitting.
return;
}
// LooperStatsService打开的情况下，会设置sObserver
final Observer observer = sObserver;
long slowDispatchThresholdMs = me.mSlowDispatchThresholdMs;
long slowDeliveryThresholdMs = me.mSlowDeliveryThresholdMs;
if (thresholdOverride > 0) {
slowDispatchThresholdMs = thresholdOverride;
slowDeliveryThresholdMs = thresholdOverride;
}
final boolean logSlowDelivery = (slowDeliveryThresholdMs > 0) && (msg.when > 0);
final boolean logSlowDispatch = (slowDispatchThresholdMs > 0);
final boolean needStartTime = logSlowDelivery || logSlowDispatch;
final boolean needEndTime = logSlowDispatch;
final long dispatchStart = needStartTime ? SystemClock.uptimeMillis() : 0;
final long dispatchEnd;
Object token = null;
if (observer != null) {
token = observer.messageDispatchStarting();
}
try {
msg.target.dispatchMessage(msg);
if (observer != null) {
observer.messageDispatched(token, msg);
}
dispatchEnd = needEndTime ? SystemClock.uptimeMillis() : 0;
} catch (Exception exception) {
if (observer != null) {
observer.dispatchingThrewException(token, msg, exception);
}
throw exception;
} finally {
ThreadLocalWorkSource.restore(origWorkSource);
if (traceTag != 0) {
Trace.traceEnd(traceTag);
}
}
if (logSlowDelivery) {
if (slowDeliveryDetected) {
if ((dispatchStart - msg.when) <= 10) {
Slog.w(TAG, "Drained");
slowDeliveryDetected = false;
}
} else {
if (showSlowLog(slowDeliveryThresholdMs, msg.when, dispatchStart, "delivery",
msg)) {
// Once we write a slow delivery log, suppress until the queue drains.
slowDeliveryDetected = true;
}
}
}
if (logSlowDispatch) {
showSlowLog(slowDispatchThresholdMs, dispatchStart, dispatchEnd, "dispatch", msg);
}
}
简单来说Looper每次处理Message的流程就是，在消息发给App处理之前、之后分别回调Observer的接口，实现记录。其中，慢速的Message处理也会在这里检查并打印日志。
LooperStatsService实际上利用了Looper提供的Observer机制，打开后它设置了sObserver，接受Message Loop的回调，在回调中记录数据并做统计。
LoopStats实现性能数据记录
LooperStatsService借助LoopStats实现数据记录。在Message派发前，记录三个数据：开机后经过的时间（elpased real time，包含系统休眠）、开机后经过的时间（uptime，不包括系统休眠）、当前线程消耗的时间。
public Object messageDispatchStarting() {
if (deviceStateAllowsCollection() && shouldCollectDetailedData()) {
DispatchSession session = mSessionPool.poll();
session = session == null ? new DispatchSession() : session;
session.startTimeMicro = getElapsedRealtimeMicro();
session.cpuStartMicro = getThreadTimeMicro();
session.systemUptimeMillis = getSystemUptimeMillis();
return session;
}
return DispatchSession.NOT_SAMPLED;
}
其中，deviceStateAllowsCollection()的判断逻辑是“设备未在充电状态”，shouldCollectDetailedData()用于实现上述设置的采样时间间隔。
LooperStatsService区分不同的Message分别进行统计，统计的信息存储于Entry中：
private static class Entry {
public final int workSourceUid;
public final Handler handler;
public final String messageName;
public final boolean isInteractive;
public long messageCount;
public long recordedMessageCount;
public long exceptionCount;
public long totalLatencyMicro;
public long maxLatencyMicro;
public long cpuUsageMicro;
public long maxCpuUsageMicro;
public long recordedDelayMessageCount;
public long delayMillis;
public long maxDelayMillis;
...
}
其中，主要信息是messageName，messageCount记录消息派发的次数，recordedMessageCount记录消息被LooperStats采样并记录到的次数。
messageCount和recordedMessageCount的差异是：每个消息都让messageCount +1，而满足前述参数设置的采样时间间隔的消息才会被采样、记录，被采样的消息才会让recordedMessageCount +1。
totalLatencyMicro记录该类型的消息花费的总时间，计算方法是消息派发前、处理完成后两者的elpased time（开机后经过的时间，包含系统或进程休眠）时间差。
maxLatencyMicro计算该类型的消息在某一次派发、处理花费的最大时间，同样是elpased time。
cpuUsageMicro和maxCpuUsageMicro，分别计算该类型消息处理时间的总和、最大耗时。计算方法是取得线程运行时间，减去派发前的线程运行时间（即messageDispatchStarting()记录的起始值）即可得到线程处理该消息的耗时（线程实际工作时间，不包含休眠）
App Message Loop还有一个很大的特点，就是其Message可以指定某个时间再出发（如postDelayed()发出的Message）。那么在一些场景下，要求定时处理的Message可能不能准时触发，而是有一定的延时，可能也会存在性能问题或体验问题，甚至是功能异常。delayMills、maxDelayMills就用于记录发生这些延时的总时间、最大延时。计算方法是，计算派发前、处理后两者的uptime时间差（系统或进程休眠时不计时），大于Message的目标时间的值就是delay的大小。对应的，recordedDelayMessageCount记录延时发生的次数。注意这三个delay数据只针对Message.when有值（即指定了触发时间的Message）的情况才会统计。
dumpsys获取性能监控数据
可以在adb shell执行dumpsys looper_stats获取性能统计数据。
dumpsys looper_stats
Start time: 2023-05-05 17:17:08
On battery time (ms): 54297
work_source_uid,thread_name,handler_class,message_name,is_interactive,message_count,recorded_message_count,total_latency_micros,max_latency_micros,total_cpu_micros,max_cpu_micros,recorded_delay_message_count,total_delay_millis,max_delay_millis,exception_count
-1,PowerManagerService,android.os.Handler,0x2,false,5,1,72,72,68,68,1,0,0,0
com.android.systemui/u0a139,WifiHandlerThread,com.android.wifi.x.com.android.internal.util.StateMachine$SmHandler,0x20053,false,9,1,31576,31576,9055,9055,1,1,1,0
com.tencent.android.qqdownloader/u0a164,PowerManagerService,android.os.Handler,0x2,false,4,1,1360,1360,98,98,1,0,0,0
com.tencent.android.qqdownloader/u0a164,SchedPolicyExecutor,com.android.server.performance.PolicyExecutor$1,0x1,false,7,1,22,22,20,20,1,0,0,0
如上，当CPU时间、消息处理时间、消息延迟时间等出现异常数值时，即可通过对应的线程、消息来确定耗时的消息、执行缓慢的流程。
