本文所有代码基于Android 12
今天我们来认识一下这个比较不为人所知的framework层的系统服务,LooperStatsService
。
创作不易,请求一个一键三连,关注、点赞、觉得有用或者有趣好玩的话可以转发给朋友看看😋
未经同意不得转载(防止卖课的洗文)
LooperStatsService
是一个系统服务,在SystemServer初始化的时候会同时初始化这个服务,并可以监测SystemServer中Looper的消息调度,下面简单介绍下这个服务有什么功能。
- 统计msg被执行时的消耗的时间、消耗的cpu时间、执行延迟的时间。
- 统计msg被执行的次数、执行中错误的次数、执行延迟的次数。
- 提供adb shell dump服务,把记录的数据打印出来。
LooperStatsService的使用
通过执行命令来手动打开或者关闭SystemServer中Looper的消息调度的数据统计
adb shell setprop debug.sys.looper_stats_enabled true // 打开
adb shell setprop debug.sys.looper_stats_enabled false // 关闭
adb shell looper_stats enable // 打开
adb shell looper_stats disable // 关闭
执行下面的命令可以打印出统计的数据
adb shell dumpsys looper_stats
# 打印出来的数据长这样
Start time: 2022-04-09 02:53:46
On battery time (ms): 29576717
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,ActivityManager,com.android.server.am.BroadcastQueue$BroadcastHandler,0xc8,false,196,1,537,537,511,511,1,0,0,0
-1,OomAdjuster,android.os.Handler,0x0,false,72,1,7872,7872,7704,7704,1,0,0,0
-1,PowerManagerService,android.os.Handler,0x2,false,559,2,381,307,370,297,2,1,1,0
-1,PowerManagerService,android.os.Handler,android.app.LoadedApk$ReceiverDispatcher$Args$$ExternalSyntheticLambda0,false,62,1,117,117,113,113,1,0,0,0
-1,PowerManagerService,android.os.Handler,com.android.server.display.DisplayPowerState$4,false,1032,1,105,105,102,102,1,0,0,0
-1,PowerManagerService,android.view.Choreographer$FrameHandler,android.view.Choreographer$FrameDisplayEventReceiver,false,1086,2,9769,5866,4412,2248,2,0,0,0
-1,android.anim,android.os.Handler,com.android.server.wm.InputMonitor$UpdateInputWindows,false,764,2,682,523,449,292,2,1,1,0
-1,android.anim,android.os.Handler,com.android.server.wm.WindowSurfacePlacer$Traverser,false,274,1,673,673,599,599,1,1,1,0
-1,android.anim,android.view.Choreographer$FrameHandler,android.view.Choreographer$FrameDisplayEventReceiver,false,3694,7,1964,590,1417,447,7,6,2,0
-1,android.anim.lf,android.view.Choreographer$FrameHandler,android.view.Choreographer$FrameDisplayEventReceiver,false,1896,2,693,444,435,271,2,1,1,0
com.android.systemui/u0a87,main,android.os.Handler,0x425,false,576,1,29,29,29,29,1,0,0,0
com.android.systemui/u0a87,main,com.android.server.notification.NotificationManagerService$WorkerHandler,com.android.server.notification.NotificationManagerService$CancelNotificationRunnable,false,237,2,236,158,197,122,2,0,0,0
com.android.cellbroadcastreceiver.module/u0a93,android.ui,com.android.server.am.ActivityManagerService$UiHandler,com.android.server.am.UidObserverController$$ExternalSyntheticLambda0,false,17,1,308,308,309,309,1,0,0,0
com.wandoujia.phoenix2/u0a97,PowerManagerService,android.os.Handler,0x2,false,29,1,19,19,18,18,1,0,0,0
com.wandoujia.phoenix2/u0a97,batterystats-handler,android.os.Handler,com.android.server.am.BatteryStatsService$$ExternalSyntheticLambda11,false,48,1,191,191,191,191,1,0,0,0
com.wandoujia.phoenix2/u0a97,main,com.android.server.notification.NotificationManagerService$WorkerHandler,com.android.server.notification.NotificationManagerService$NotificationListeners$$ExternalSyntheticLambda5,false,6,2,407,213,405,213,2,1,1,0
com.tencent.qqmusic/u0a98,AudioService,com.android.server.audio.AudioService$AudioHandler,0x1d,false,8,1,119,119,117,117,1,0,0,0
com.tencent.qqmusic/u0a98,android.ui,com.android.server.am.ActivityManagerService$UiHandler,0x1f,false,225,1,32,32,32,32,1,0,0,0
一般关注以下这几个值就可以:total_latency_micros,max_latency_micros,total_cpu_micros,max_cpu_micros,后面会分析到这几个值是怎么计算出来的。
执行下面的命令可以重置统计的数据
adb shell looper_stats reset
执行下面的命令可以设置采样间隔,默认是1000,采样间隔越低,采样越频繁
adb shell looper_stats sampling_interval 2000 // 设置采样间隔为2000
通过执行下面的命令可以控制采样间隔、是否忽略电池状态(电池正在充电的时候会停止进行统计)、打开或者关闭SystemServer中Looper的消息调度的数据统计。(键值对顺序没有要求,只需要设置自己需要改变的键值对即可,不改变的可忽略)
adb shell settings put global looper_stats enabled=true,ignore_battery_status=false,track_screen_state=false,sampling_interval=2000
LooperStatsService在Looper中的作用
通过LooperStatsService
这个名字可以看出,它是一个和Looper中的数据统计有关,而它会统计哪些Looper呢?我们带着疑问继续分析。下面代码只显示一些与LooperStatsService
有关的代码,其他无关代码将会被省略。
在Looper中搜LooperStatsService字段,并不能直接搜到数据,但如果读过Looper源码的同学可能会知道,Looper中比较重要的方法是Looper#loopOnce
方法,这个方法的功能是从MessageQueue
中取出一条Message
,然后分发到Message指定的target handler
执行,我们从这个方法入手,看看能不能找到什么数据被收集到LooperStatsService
中。
frameworks/base/core/java/android/os/Looper.java
private static boolean loopOnce(final Looper me, final long ident, final int thresholdOverride) {
// ...
// 1
final Observer observer = sObserver;
// ...
if (observer != null) {
token = observer.messageDispatchStarting();
}
// ...
try {
// ...
// 2
msg.target.dispatchMessage(msg);
if (observer != null) {
observer.messageDispatched(token, msg);
}
// ...
} catch (Exception exception) {
if (observer != null) {
observer.dispatchingThrewException(token, msg, exception);
}
throw exception;
} finally {
// ...
}
// ...
return true;
}
注释2作为Looper#loopOnce
中最重要的调用,它的前后分别被observer
调用messageDispatchStarting
和messageDispatched
包围起来了,如果dispatchMessage发生异常还会在catch中通过dispatchingThrewException
调用反馈给observer
,从1处可以看到这里有一个全局静态变量sObserver
赋值给observer变量,而sObserver
作为Looper的全局静态变量,在初始化的时候为null,通过调用Looper#setObserver
的静态方法可以给Looper设置一个Observer,但这个是一个@hide方法,但通过反射和绕过hidden api应用也是可以给自己的Looper设置这个Observer。回归正题,通过查看Looper#setObserver
方法的调用方,可以看到在系统源码中,LooperStatsService#setEnabled
会调用此方法。
frameworks/base/services/core/java/com/android/server/LooperStatsService.java
private void setEnabled(boolean enabled) {
if (mEnabled != enabled) {
mEnabled = enabled;
mStats.reset();
mStats.setAddDebugEntries(enabled);
Looper.setObserver(enabled ? mStats : null);
}
}
这里LooperStatsService把mStats
设置到自己的Looper中作为Observer,由此可以看出,Looper数据统计的核心类就是LooperStats mStats
,在LooperStatsService创建的时候创建出来
frameworks/base/services/core/java/com/android/server/LooperStatsService.java
public Lifecycle(Context context) {
super(context);
// DEFAULT_SAMPLING_INTERVAL = 1000
// DEFAULT_ENTRIES_SIZE_CAP = 1500
mStats = new LooperStats(DEFAULT_SAMPLING_INTERVAL, DEFAULT_ENTRIES_SIZE_CAP);
mService = new LooperStatsService(getContext(), mStats);
mSettingsObserver = new SettingsObserver(mService);
}
所以这里可以大致总结一下,LooperStatsService
在初始化的时候创建出LooperStats mStats
,并通过Looper.setObserver
设置到SystemServer的Looper中(功能打开的情况下),作为统计消息被分发之前messageDispatchStarting
、消息执行之后messageDispatched
、消息执行异常dispatchingThrewException
的插桩。这里可以看到DEFAULT_ENTRIES_SIZE_CAP
的值为1500,而LooperStats
中没有其他方法可以更改这个值的函数,所以这里统计的msg的上限就是1500条(也可以说是1500种msg)。
数据统计类LooperStats解析
LooperStats
实现了接口Looper.Observer
/** {@hide} */
public interface Observer {
/**
* Called right before a message is dispatched.
*
* <p> The token type is not specified to allow the implementation to specify its own type.
*
* @return a token used for collecting telemetry when dispatching a single message.
* The token token must be passed back exactly once to either
* {@link Observer#messageDispatched} or {@link Observer#dispatchingThrewException}
* and must not be reused again.
*
*/
Object messageDispatchStarting();
/**
* Called when a message was processed by a Handler.
*
* @param token Token obtained by previously calling
* {@link Observer#messageDispatchStarting} on the same Observer instance.
* @param msg The message that was dispatched.
*/
void messageDispatched(Object token, Message msg);
/**
* Called when an exception was thrown while processing a message.
*
* @param token Token obtained by previously calling
* {@link Observer#messageDispatchStarting} on the same Observer instance.
* @param msg The message that was dispatched and caused an exception.
* @param exception The exception that was thrown.
*/
void dispatchingThrewException(Object token, Message msg, Exception exception);
}
messageDispatchStarting
LooperStats
是这样来实现messageDispatchStarting
接口函数的:
frameworks/base/core/java/com/android/internal/os/LooperStats.java
@Override
public Object messageDispatchStarting() {
// 判断是否采样这个msg 不采样则返回DispatchSession.NOT_SAMPLED
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;
}
private static class DispatchSession {
static final DispatchSession NOT_SAMPLED = new DispatchSession();
public long startTimeMicro;
public long cpuStartMicro;
public long systemUptimeMillis;
}
返回一个DispatchSession
对象作为被trace的message的token,而DispatchSession
是LooperStats
的一个静态内部类,里面包含三个long类型的变量,都是表示消息分发之前的时间,分别是
- startTimeMicro: 开机到现在包括系统深度睡眠的微秒
SystemClock.elapsedRealtimeNanos() / 1000
- cpuStartMicro: 当前线程占用cpu的微秒
SystemClock.currentThreadTimeMicro()
- systemUptimeMillis: 开机到现在不包括深度睡眠的毫秒
SystemClock.uptimeMillis()
接下来的所有数据都是根据以上三个值作为基础值,而进行统计的。
messageDispatched(Object token, Message msg)
当消息被分发之后,把当前的时间和之前存下来的数据进行相减,则是执行这条消息所花费的时间,代码如下:
frameworks/base/core/java/com/android/internal/os/LooperStats.java
@Override
public void messageDispatched(Object token, Message msg) {
// ...
DispatchSession session = (DispatchSession) token;
Entry entry = findEntry(msg, /* allowCreateNew= */session != DispatchSession.NOT_SAMPLED);
if (entry != null) {
synchronized (entry) {
// 自加msg执行的次数
entry.messageCount++;
// messageDispatchStarting返回DispatchSession.NOT_SAMPLED则不采样此次的dispatch
if (session != DispatchSession.NOT_SAMPLED) {
entry.recordedMessageCount++;
final long latency = getElapsedRealtimeMicro() - session.startTimeMicro;
final long cpuUsage = getThreadTimeMicro() - session.cpuStartMicro;
entry.totalLatencyMicro += latency;
entry.maxLatencyMicro = Math.max(entry.maxLatencyMicro, latency);
entry.cpuUsageMicro += cpuUsage;
entry.maxCpuUsageMicro = Math.max(entry.maxCpuUsageMicro, cpuUsage);
if (msg.getWhen() > 0) {
final long delay = Math.max(0L, session.systemUptimeMillis - msg.getWhen());
entry.delayMillis += delay;
entry.maxDelayMillis = Math.max(entry.maxDelayMillis, delay);
entry.recordedDelayMessageCount++;
}
}
}
}
// ...
}
private static class Entry {
// 标识哪个uid把msg enqueue到MessageQueue 只会在system_server进程使用
public final int workSourceUid;
// msg的target handler
public final Handler handler;
// 有callback的handler为callback类名 没有callback则为msg.what的十六进制表示
public final String messageName;
// 标识执行这条msg时候的屏幕的亮灭 默认不跟踪这个值 为false
public final boolean isInteractive;
// 该msg被执行的次数,如果messageDispatchStarting返回DispatchSession.NOT_SAMPLED
// messageDispatched会自加messageCount,而不自加recordedMessageCount
public long messageCount;
// 该msg被执行且采样到的次数
public long recordedMessageCount;
// 执行这个msg翻车的次数(回调dispatchingThrewException)
public long exceptionCount;
// 执行这个msg总的消耗的时间
public long totalLatencyMicro;
// 执行这个msg最大消耗的时间
public long maxLatencyMicro;
// 执行这个msg消耗的总cpu时间
public long cpuUsageMicro;
// 执行这个msg消耗的最大的cpu时间
public long maxCpuUsageMicro;
// 这个msg被延迟执行的次数
public long recordedDelayMessageCount;
// 这个msg被延迟执行的累加毫秒数
public long delayMillis;
// 这个msg被延迟执行的最大延迟时间
public long maxDelayMillis;
}
Entry
作为message所有数据记录的类,作为静态内部类声明在LooperStats
中
dispatchingThrewException(Object token, Message msg, Exception exception)
当消息执行翻车的时候,翻车的次数也会被执行下来
frameworks/base/core/java/com/android/internal/os/LooperStats.java
@Override
public void dispatchingThrewException(Object token, Message msg, Exception exception) {
// ...
if (entry != null) {
synchronized (entry) {
entry.exceptionCount++;
}
}
// ...
}
几个有趣的地方
有趣一:LooperStatsService
在初始化读取了配置中这个键track_screen_state
的值,并执行自己的setTrackScreenInteractive
函数,但是最后并不会设置到所有数据统计的地方LooperStats
,所以在配置中配置这个值是没有效果的。
frameworks/base/services/core/java/com/android/server/LooperStatsService.java
private void setTrackScreenInteractive(boolean enabled) {
if (mTrackScreenInteractive != enabled) {
// 没有调用
// mStats.setTrackScreenInteractive(enable);
mTrackScreenInteractive = enabled;
mStats.reset();
}
}
// 正确示范
private void setIgnoreBatteryStatus(boolean ignore) {
if (mIgnoreBatteryStatus != ignore) {
// 调用了
mStats.setIgnoreBatteryStatus(ignore);
mIgnoreBatteryStatus = ignore;
mStats.reset();
}
}
这个值的作用是设置消息执行与亮灭屏的关联,设置关联的话,亮屏和灭屏是两种不一样的统计数据,也就是亮屏下执行这条msg是一个entry,灭屏下执行这条数据是另外一个entry,可能某些msg的耗时对于亮屏或者灭屏下的状态会比较敏感,所以需要分开统计,默认为false。如果真的想消息统计关联亮灭屏可以手动调一下LooperStats#setTrackScreenInteractive
,记得调用之后一定要reset一下LooperStats中的数据,即调用LooperStats#reset
,重新统计数据。
有趣二:LooperStats
类中有两个比较特殊的Entry
frameworks/base/core/java/com/android/internal/os/LooperStats.java
private final Entry mOverflowEntry = new Entry("OVERFLOW");
private final Entry mHashCollisionEntry = new Entry("HASH_COLLISION");
mOverflowEntry
的作用:当当前存储的entries数量多于初始化时设置的值时(1500种msg),就会把后面所有与前面1500种不同的msg的统计数据存入到这个mOverflowEntry
中。
想想其实也是这个道理,前面都出现过1500种msg,那后面的msg的统计的收益也就不大了。其实也可以做成这样:如果某些msg的耗时太大,可以把前面耗时不大的Entry替换,这样的策略,毕竟这个服务存在的意义就是帮开发者把一些耗时的消息从主Looper找出来,放到bg thread进行。
mHashCollisionEntry
的作用:当通过msg和isInteractive从mEntries
中找到的entry与msg的workSourceUid
、handler
、thread
、isInteractive
(亮灭屏)中有任何一项与当前统计msg的不一样的时候表明查找id的时候发生了hash冲突,而这里处理hash冲突的方法就是把数据全统计在这个entry中。hash算法如下:
frameworks/base/core/java/com/android/internal/os/LooperStats.java
static int idFor(Message msg, boolean isInteractive) {
int result = 7;
result = 31 * result + msg.workSourceUid;
result = 31 * result + msg.getTarget().getLooper().getThread().hashCode();
result = 31 * result + msg.getTarget().getClass().hashCode();
result = 31 * result + (isInteractive ? 1231 : 1237);
if (msg.getCallback() != null) {
return 31 * result + msg.getCallback().getClass().hashCode();
} else {
return 31 * result + msg.what;
}
}
当这两个entry中的messageCount
或者exceptionCount
大于0的时候则会在dumpsys中显示,反之则不显示这两个entry。
有趣三:dumpsys的时候会添加几个debug的entry,但打印的时候会被过滤
frameworks/base/core/java/com/android/internal/os/LooperStats.java
public List<ExportedEntry> getEntries() {
// ...
// Debug entries added to help validate the data.
if (mAddDebugEntries && mBatteryStopwatch != null) {
exportedEntries.add(createDebugEntry("start_time_millis", mStartElapsedTime));
exportedEntries.add(createDebugEntry("end_time_millis", SystemClock.elapsedRealtime()));
exportedEntries.add(
createDebugEntry("battery_time_millis", mBatteryStopwatch.getMillis()));
exportedEntries.add(createDebugEntry("sampling_interval", mSamplingInterval));
}
return exportedEntries;
}
// frameworks/base/services/core/java/com/android/server/LooperStatsService.java
@Override
protected void dump(FileDescriptor fd, PrintWriter pw, String[] args) {
// ...
for (LooperStats.ExportedEntry entry : entries) {
if (entry.messageName.startsWith(LooperStats.DEBUG_ENTRY_PREFIX)) {
// Do not dump debug entries.
continue;
}
// ...
}
- "start_time_millis":开始统计Looper中数据的时间,
LooperStats#reset
会重置这个值 - "end_time_millis":dumpsys执行的时间
- "battery_time_millis":开始执行数据统计后经历手机不在充电的时间,
mIgnoreBatteryStatus
被设置为true时,在充电也会进行Looper的数据统计,但不被累加到battery_time_millis
,LooperStats#reset
会重置这个值 - "sampling_interval":采样间隔
说在后面
上面这些统计Looper中消息的执行的逻辑,结合字节的ANR分析逻辑,也许你们能复刻字节的Raster工具,帮助自己的App分析Looper中的消息延迟或者主线程消息执行缓慢导致的ANR,下面附上几篇字节的文章链接,方便跳转。