基于Android 12--LooperStatsService的使用与功能实现分析

本文所有代码基于Android 12

今天我们来认识一下这个比较不为人所知的framework层的系统服务，LooperStatsService。

LooperStatsService是一个系统服务，在SystemServer初始化的时候会同时初始化这个服务，并可以监测SystemServer中Looper的消息调度，下面简单介绍下这个服务有什么功能。

  1. 统计msg被执行时的消耗的时间、消耗的cpu时间、执行延迟的时间。
  2. 统计msg被执行的次数、执行中错误的次数、执行延迟的次数。
  3. 提供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"：采样间隔
©著作权归作者所有,转载或内容合作请联系作者
  • 人面猴
    序言：七十年代末，一起剥皮案震惊了整个滨河市，随后出现的几起案子，更是在滨河造成了极大的恐慌，老刑警刘岩，带你破解...
    沈念sama阅读 206,214评论 6赞 481
  • 死咒
    序言：滨河连续发生了三起死亡事件，死亡现场离奇诡异，居然都是意外死亡，警方通过查阅死者的电脑和手机，发现死者居然都...
    沈念sama阅读 88,307评论 2赞 382
  • 救了他两次的神仙让他今天三更去死
    文/潘晓璐 我一进店门，熙熙楼的掌柜王于贵愁眉苦脸地迎上来，“玉大人，你说我怎么就摊上这事。” “怎么了？”我有些...
    开封第一讲书人阅读 152,543评论 0赞 341
  • 道士缉凶录：失踪的卖姜人
    文/不坏的土叔 我叫张陵，是天一观的道长。 经常有香客问我，道长，这世上最难降的妖魔是什么？ 我笑而不...
    开封第一讲书人阅读 55,221评论 1赞 279
  • 港岛之恋（遗憾婚礼）
    正文 为了忘掉前任，我火速办了婚礼，结果婚礼上，老公的妹妹穿的比我还像新娘。我一直安慰自己，他们只是感情好，可当我...
    茶点故事阅读 64,224评论 5赞 371
  • 恶毒庶女顶嫁案：这布局不是一般人想出来的
    文/花漫 我一把揭开白布。 她就那样静静地躺着，像睡着了一般。 火红的嫁衣衬着肌肤如雪。 梳的纹丝不乱的头发上，一...
    开封第一讲书人阅读 49,007评论 1赞 284
  • 城市分裂传说
    那天，我揣着相机与录音，去河边找鬼。 笑死，一个胖子当着我的面吹牛，可吹牛的内容都是我干的。 我是一名探鬼主播，决...
    沈念sama阅读 38,313评论 3赞 399
  • 双鸳鸯连环套：你想象不到人心有多黑
    文/苍兰香墨 我猛地睁开眼，长吁一口气：“原来是场噩梦啊……” “哼！你这毒妇竟也来了？” 一声冷哼从身侧响起，我...
    开封第一讲书人阅读 36,956评论 0赞 259
  • 万荣杀人案实录
    序言：老挝万荣一对情侣失踪，失踪者是张志新（化名）和其女友刘颖，没想到半个月后，有当地人在树林里发现了一具尸体，经...
    沈念sama阅读 43,441评论 1赞 300
  • 护林员之死
    正文 独居荒郊野岭守林人离奇死亡，尸身上长有42处带血的脓包…… 初始之章·张勋 以下内容为张勋视角 年9月15日...
    茶点故事阅读 35,925评论 2赞 323
  • 白月光启示录
    正文 我和宋清朗相恋三年，在试婚纱的时候发现自己被绿了。 大学时的朋友给我发了我未婚夫和他白月光在一起吃饭的照片。...
    茶点故事阅读 38,018评论 1赞 333
  • 活死人
    序言：一个原本活蹦乱跳的男人离奇死亡，死状恐怖，灵堂内的尸体忽然破棺而出，到底是诈尸还是另有隐情，我是刑警宁泽，带...
    沈念sama阅读 33,685评论 4赞 322
  • 日本核电站爆炸内幕
    正文 年R本政府宣布，位于F岛的核电站，受9级特大地震影响，放射性物质发生泄漏。R本人自食恶果不足惜，却给世界环境...
    茶点故事阅读 39,234评论 3赞 307
  • 男人毒药：我在死后第九天来索命
    文/蒙蒙 一、第九天 我趴在偏房一处隐蔽的房顶上张望。 院中可真热闹，春花似锦、人声如沸。这庄子的主人今日做“春日...
    开封第一讲书人阅读 30,240评论 0赞 19
  • 一桩弑父案，背后竟有这般阴谋
    文/苍兰香墨 我抬头看了看天上的太阳。三九已至，却和暖如春，着一层夹袄步出监牢的瞬间，已是汗流浃背。 一阵脚步声响...
    开封第一讲书人阅读 31,464评论 1赞 261
  • 情欲美人皮
    我被黑心中介骗来泰国打工， 没想到刚下飞机就差点儿被人妖公主榨干…… 1. 我叫王不留，地道东北人。 一个月前我还...
    沈念sama阅读 45,467评论 2赞 352
  • 代替公主和亲
    正文 我出身青楼，却偏偏与公主长得像，于是被迫代替她去往敌国和亲。 传闻我的和亲对象是个残疾皇子，可洞房花烛夜当晚...
    茶点故事阅读 42,762评论 2赞 345

推荐阅读更多精彩内容