简介
在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:
1
| settings put global looper_stats sampling_interval=100,track_screen_state=true,enabled=true
|
启动流程非常简单,先参数值初始化,然后将Observer设置到Looper。
也可以采用adb命令的方式来控制:
1 2 3 4 5 6
| 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提供回调接口来实现上述需求:
1 2 3 4 5
| public interface Observer { Object messageDispatchStarting(); void messageDispatched(Object token, Message msg); void dispatchingThrewException(Object token, Message msg, Exception exception); }
|
前两个接口分别在一个消息处理前、一个消息完成处理时回调。第三个接口是Message处理过程中抛出了异常时回调。
App主事件循环实际上可以抽象为如下流程:
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 57 58 59 60 61 62 63 64 65 66 67 68 69 70 71
| public static void loop() { final Looper me = myLooper(); final MessageQueue queue = me.mQueue;
boolean slowDeliveryDetected = false;
for (;;) { Message msg = queue.next(); if (msg == null) { return; }
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)) { 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,不包括系统休眠)、当前线程消耗的时间。
1 2 3 4 5 6 7 8 9 10 11
| 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中:
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17
| 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获取性能统计数据。
1 2 3 4 5 6 7
| 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
|
如上,当CPU时间、消息处理时间、消息延迟时间等出现异常数值时,即可通过对应的线程、消息来确定耗时的消息、执行缓慢的流程。