LooperStatsService的使用与功能实现分析

作者: ContentPane | 来源:发表于2022-05-19 00:02 被阅读0次

本文所有代码基于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，下面附上几篇字节的文章链接，方便跳转。

今日头条 ANR 优化实践系列 - 设计原理及影响因素

今日头条 ANR 优化实践系列 - 监控工具与分析思路

今日头条 ANR 优化实践系列分享 - 实例剖析集锦

LooperStatsService的使用与功能实现分析

LooperStatsService的使用

LooperStatsService在Looper中的作用

数据统计类LooperStats解析

messageDispatchStarting

messageDispatched(Object token, Message msg)

dispatchingThrewException(Object token, Message msg, Exception exception)

几个有趣的地方

说在后面

相关文章

网友评论

延伸阅读

深度阅读

栏目导航

热点阅读