Android性能监控：主循环性能统计LooperStatsService详解

作者：飞起来_飞过来

简介

在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时间、消息处理时间、消息延迟时间等出现异常数值时，即可通过对应的线程、消息来确定耗时的消息、执行缓慢的流程。

根据不同的性能监控问题，我们需要采用不同的性能优化手段，而目前还是有些人群对于性能优化中间的一些优化手段掌握的不是很熟练，因此针对性能优化中间的所有不同类型的优化手段进行了归类整理，有启动优化、内存优化、网络优化、卡顿优化、存储优化……等，整合成名为《Android 性能优化核心知识点手册》，大家可以参考下：