作者：唐子玄

前言

线上 App 某个版本之后，服务端同学从埋点数据中发现一个奇怪的现象：“所有界面的 Activity.onPause() 过后，得等 10 秒整，才回调 Activity.onStop()。”

这么扯吗？是不是统计数据有问题？

怎么可能？Activity 生命周期是系统控制的呀？

为啥是如此诡异，正正好好的 10 秒？

App 岂不是会很卡？ANR 蹭蹭往上？

从哪切入排查？

接手该问题后，一连串问号涌现。。。

一、检测 & 复现

在一口闷三杯咖啡之后，我决定。。先上个厕所。（咖啡利尿）

定神之后，我做出了一个关键决定：先稳定复现问题。这是修复任何问题的第一步。

于是乎写出了这样的检测代码：

class MyApplication : Application() {override fun onCreate() {super.onCreate()registerActivityLifecycleCallbacks(object : ActivityLifecycleCallbacks {override fun onActivityPaused(activity: Activity) {val now = System.currentTimeMillis()Log.v("test", "Pause(${activity.componentName})${now.milliseconds.inWholeSeconds}")}override fun onActivityStopped(activity: Activity) {val now = System.currentTimeMillis()Log.v("test", "Stop(${activity.componentName})${now.milliseconds.inWholeSeconds}")}})}
}

利用ActivityLifecycleCallbacks对所有 Activity 生命周期进行监听，并分别在 pause 和 stop 中打印当前秒数。

其中的milliseconds是 Long 的扩展方法：

public inline val Long.milliseconds get() = toDuration(DurationUnit.MILLISECONDS)

它用于将 Long 转换成一个Duration对象。这样就可以运用 Duration 提供的各种方法方便地处理时间。这次用到的是inWholeSeconds：

// kotlin.time.Duration.kt
public val inWholeSeconds: Longget() = toLong(DurationUnit.SECONDS)

它用于将 Duration 转换为秒。

然后启动 App，随意进行了一个页面跳转，日志如下：

V/test: Pause(Activity1) time=1657277824
V/test: Stop(Activity1) time=1657277834

很明显，间隔 10 秒。

反复试了多个界面跳转，都是如此。。。

二、定位1：启动页耗时操作？

到底是啥导致生命周期回调超时？

定位的过程犹如大海捞针！

第一个猜测：“是不是启动页在主线程做了耗时操作？”

因为是所有界面生命周期都有问题，所以把焦点锁定在 BaseActivity。但它的 onCreate，onStart，onResume。没做什么特别的事情。

失望。。。。。。

三、定位2：主线程消息队列阻塞？

Activity 生命周期回调发生在主线程。

所有发生在主线程的操作，都应该经由主线程消息队列。

看下源码，验证一番：

public final class ActivityThread {// 和主线程消息队列关联的 Handlerfinal H mH = new H();private class H extends Handler {public void handleMessage(Message msg) {switch (msg.what) {// 处理 pause 消息case PAUSE_ACTIVITY: {...// 触发 onPause()handlePauseActivity((IBinder) args.arg1, false,(args.argi1 & USER_LEAVING) != 0, args.argi2,(args.argi1 & DONT_REPORT) != 0, args.argi3);maybeSnapshot();Trace.traceEnd(Trace.TRACE_TAG_ACTIVITY_MANAGER);} break;// 处理 stop 消息case STOP_ACTIVITY_SHOW: {...// 触发 onStop()handleStopActivity((IBinder) args.arg1, true, args.argi2, args.argi3);Trace.traceEnd(Trace.TRACE_TAG_ACTIVITY_MANAGER);} break;}}}
}

可见 Activity 的生命周期回调都要经过主线程的消息队列。

消息是谁发的？

private class ApplicationThread extends IApplicationThread.Stub {public final void schedulePauseActivity(IBinder token, boolean finished,boolean userLeaving, int configChanges, boolean dontReport) {int seq = getLifecycleSeq();// 发送 pause 消息sendMessage(finished ? H.PAUSE_ACTIVITY_FINISHING : H.PAUSE_ACTIVITY,token,(userLeaving ? USER_LEAVING : 0) | (dontReport ? DONT_REPORT : 0),configChanges,seq);}// 发送 stop 消息public final void scheduleStopActivity(IBinder token, boolean showWindow,int configChanges) {int seq = getLifecycleSeq();sendMessage(showWindow ? H.STOP_ACTIVITY_SHOW : H.STOP_ACTIVITY_HIDE,token, 0, configChanges, seq);}

Activity 生命周期回调是 ApplicationThread 触发的，它是一个IApplicationThread.Stub，ActivityManagerService 会在系统进程通过这个接口通知 App 进程调用 Activity 生命周期方法。

看完源码，“主线程消息队列阻塞”的猜想能自圆其说了：

推论1：因为主线程有太多的消息，导致原本该被立刻执行的生命周期消息，迟迟得不到执行。（这个推论是有问题的，后面会一步步纠正）

四、显形

猜想归猜想，如何石锤？

手段1：能不能把主线程处理每一条消息的日志打印出来？

还好 Looper 留了一个后门：

Looper.getMainLooper().setMessageLogging{ msg ->Log.v("test","looper message = $msg")
}

setMessageLogging()是一个 Looper 的方法，用于打印消息循环中的每一条消息：

// android.os.Looper.java// 注入打印接口
public void setMessageLogging(@Nullable Printer printer) {mLogging = printer;
}
// 打印接口
public interface Printer {void println(String x);
}

Looper 会持有一个 Printer 接口的实例，在无限循环中，每取到一条消息就会打印它：

public final class Looper {// 持有 Printerprivate Printer mLogging;private static boolean loopOnce(final Looper me, final long ident, final int thresholdOverride) {// 取下一条消息Message msg = me.mQueue.next();if (msg == null) {return false;}// 1. 打印“消息开始分发”final Printer logging = me.mLogging;if (logging != null) {logging.println(">>>>> Dispatching to " + msg.target + " "+ msg.callback + ": " + msg.what);}// 分发消息try {msg.target.dispatchMessage(msg);...}...// 2. 打印“消息处理完毕”if (logging != null) {logging.println("<<<<< Finished to " + msg.target + " " + msg.callback);}// 回收消息msg.recycleUnchecked();...}
}

共有两个消息打印时机，一是在获取消息后，分发消息前，二是在消息处理完毕后。

跑一下 App，如洪水般的 log 涌入屏幕：

V/test: looper message = >>>>> Dispatching to Handler (android.view.Choreographer$FrameHandler) {eb21acd} android.view.Choreographer$FrameDisplayEventReceiver@d8e0f82: 0
V/test: looper message = <<<<< Finished to Handler (android.view.Choreographer$FrameHandler) {eb21acd} android.view.Choreographer$FrameDisplayEventReceiver@d8e0f82
V/test: looper message = >>>>> Dispatching to Handler (android.view.Choreographer$FrameHandler) {eb21acd} android.view.Choreographer$FrameDisplayEventReceiver@d8e0f82: 0
V/test: looper message = <<<<< Finished to Handler (android.view.Choreographer$FrameHandler) {eb21acd} android.view.Choreographer$FrameDisplayEventReceiver@d8e0f82
V/test: looper message = >>>>> Dispatching to Handler (android.view.Choreographer$FrameHandler) {eb21acd} android.view.Choreographer$FrameDisplayEventReceiver@d8e0f82: 0
V/test: looper message = <<<<< Finished to Handler (android.view.Choreographer$FrameHandler) {eb21acd} android.view.Choreographer$FrameDisplayEventReceiver@d8e0f82
V/test: looper message = >>>>> Dispatching to Handler (android.view.Choreographer$FrameHandler) {eb21acd} android.view.Choreographer$FrameDisplayEventReceiver@d8e0f82: 0
V/test: looper message = <<<<< Finished to Handler (android.view.Choreographer$FrameHandler) {eb21acd} android.view.Choreographer$FrameDisplayEventReceiver@d8e0f82
V/test: looper message = >>>>> Dispatching to Handler (android.view.Choreographer$FrameHandler) {eb21acd} android.view.Choreographer$FrameDisplayEventReceiver@d8e0f82: 0
V/test: looper message = <<<<< Finished to Handler (android.view.Choreographer$FrameHandler) {eb21acd} android.view.Choreographer$FrameDisplayEventReceiver@d8e0f82
V/test: looper message = >>>>> Dispatching to Handler (android.view.Choreographer$FrameHandler) {eb21acd} android.view.Choreographer$FrameDisplayEventReceiver@d8e0f82: 0
V/test: looper message = <<<<< Finished to Handler (android.view.Choreographer$FrameHandler) {eb21acd} android.view.Choreographer$FrameDisplayEventReceiver@d8e0f82
V/test: looper message = >>>>> Dispatching to Handler (android.view.Choreographer$FrameHandler) {eb21acd} android.view.Choreographer$FrameDisplayEventReceiver@d8e0f82: 0
V/test: looper message = <<<<< Finished to Handler (android.view.Choreographer$FrameHandler) {eb21acd} android.view.Choreographer$FrameDisplayEventReceiver@d8e0f82
V/test: looper message = >>>>> Dispatching to Handler (android.view.Choreographer$FrameHandler) {eb21acd} android.view.Choreographer$FrameDisplayEventReceiver@d8e0f82: 0
V/test: looper message = <<<<< Finished to Handler (android.view.Choreographer$FrameHandler) {eb21acd} android.view.Choreographer$FrameDisplayEventReceiver@d8e0f82
V/test: looper message = >>>>> Dispatching to Handler (android.view.Choreographer$FrameHandler) {eb21acd} android.view.Choreographer$FrameDisplayEventReceiver@d8e0f82: 0
V/test: looper message = <<<<< Finished to Handler (android.view.Choreographer$FrameHandler) {eb21acd} android.view.Choreographer$FrameDisplayEventReceiver@d8e0f82
V/test: looper message = >>>>> Dispatching to Handler (android.view.Choreographer$FrameHandler) {eb21acd} android.view.Choreographer$FrameDisplayEventReceiver@d8e0f82: 0
V/test: looper message = <<<<< Finished to Handler (android.view.Choreographer$FrameHandler) {eb21acd} android.view.Choreographer$FrameDisplayEventReceiver@d8e0f82

这段 log 是无限循环输出的，永远也不会停下来。

从内容来看，每一条消息都被分发到 Choreographer，并交由 FrameHandler 处理。

Choreographer 负责协调“上层任务”与“垂直同步信号”。

它接收四种任务，分别是输入、动画、View树遍历、COMMIT。Choreographer 接收到任务后会将其暂存并注册下一个 vsync 信号，待信号到来时，再将当前时刻之前的所有任务都包装成异步消息通过 FrameHandler 抛到主线程执行。当主线程执行到该消息时，触摸事件就得以响应、动画就得以执行、View 就得以重绘。

关于 Choreographer 更详细的剖析，可以点击读源码长知识 | Android卡顿真的是因为”掉帧“？

https://juejin.cn/post/6864365886837686285

若 FrameHandler 有源源不断的消息，这意味着 App 在不停地产生“上层任务”。但我并未触摸屏幕，遂可把上个推论具体化一下：

推论2：界面存在无限循环的动画或重绘，导致主线程消息队列无限膨胀，原本该被立刻执行的生命周期消息，迟迟得不到执行。（这个推论依然有问题，请看下面分析~）

五、甄别

但我想把问题的范围再缩小一点，到底是动画任务还是重绘任务？它们的区别在哪里？于是乎进行了如下分析。

重绘任务在被抛给 Choreographer 之前，ViewRootImpl 会先向主线程消息队列抛一个同步消息屏障：

// android.view.ViewRootImpl.java
void scheduleTraversals() {if (!mTraversalScheduled) {mTraversalScheduled = true;// 向主线程抛同步消息屏障mTraversalBarrier = mHandler.getLooper().getQueue().postSyncBarrier();// 向 Choreographer 抛重绘任务mChoreographer.postCallback Choreographer.CALLBACK_TRAVERSAL, mTraversalRunnable, null);...}
}

同步消息屏障也是一个 Message，只不过它的 target = null：

private int postSyncBarrier(long when) {synchronized (this) {final int token = mNextBarrierToken++;// 从消息池获取新消息，并未给 msg.target 赋值final Message msg = Message.obtain();msg.markInUse();msg.when = when;msg.arg1 = token;Message prev = null;Message p = mMessages;// 从消息队列头部往后找屏障消息该插入的位置// （因为消息队列是按时间递增排序的，同步消息屏障也得遵守这个规则）if (when != 0) {while (p != null && p.when <= when) {prev = p;p = p.next;}}// 找到插入位置，屏障消息入链if (prev != null) {msg.next = p;prev.next = msg;} else {msg.next = p;mMessages = msg;}return token;}
}

Looper 无限循环时会调用MessageQueue.next()获取下一条消息：

// android.os.MessageQueue.java
Message next() {for (;;) {synchronized (this) {Message prevMsg = null;Message msg = mMessages;// 若有同步屏障，则跳过同步消息去获取第一个异步消息if (msg != null && msg.target == null) {do {prevMsg = msg;msg = msg.next;} while (msg != null && !msg.isAsynchronous());}// 获取消息成功if (msg != null) {if (now < msg.when) {nextPollTimeoutMillis = (int) Math.min(msg.when - now, Integer.MAX_VALUE);} else {// 将消息脱链并返回mBlocked = false;if (prevMsg != null) {prevMsg.next = msg.next;} else {mMessages = msg.next;}msg.next = null;msg.markInUse();return msg;}}...}}
}

所以同步屏障消息起到了优先遍历消息队列中异步消息的作用。

当 View 树遍历任务被执行时，同步消息屏障的使命就完成了，它会被移除：

// android.view.ViewRootImpl.java
void doTraversal() {if (mTraversalScheduled) {mTraversalScheduled = false;// 移除同步消息屏障mHandler.getLooper().getQueue().removeSyncBarrier(mTraversalBarrier);// View 树开始遍历performTraversals();...}
}

“是否存在同步消息屏障”就是 View 树遍历和动画任务的本质区别。

手段2：若能把某一瞬间主线程消息队列的快照打印出来，查看其中是否有同步消息屏障，就能确定是动画引起的，还是 View 重绘引起的问题。

还好 Looper 提供了这个接口dump()：

Looper.getMainLooper().dump(new Printer() {@Overridepublic void println(String x) {Log.v("message",""+x);}
}, "test");

当 App 跑起来后，尝试在不同的时间点多次打印，输出的日志总是长这个样子：

 testLooper (main, tid 2) {185d994}test  Message 0: { when=-5ms barrier=172 } // 同步消息屏障test  Message 1: { when=+57ms callback=android.view.View$UnsetPressedState target=android.view.ViewRootImpl$ViewRootHandler }test  (Total messages: 2, polling=false, quitting=false)

消息队列中总会有两条消息，第一条是同步消息屏障，第二条是触摸事件（触发打印日志的点击事件）。

有了这份日志的帮助，推论就更具有指向性：

推论3：界面中有视图在无限循环地重绘，以至于前一个同步消息屏障被移除后，一个新屏障又立马被添加到队列中，导致同步消息永远无法被执行。（这个推论还是有问题，请往下看）

六、疑团重重 -> 盖棺定论

当我准备排查是哪个视图不断重绘之前，有三个疑惑浮现出来：

只要有视图不停重绘，同步消息永远无法被执行？？
同样是通过消息机制回调生命周期方法，为啥 onPause() 执行了，而 onStop() 没有？
为啥 onStop() 总是过 10 秒之后被执行？？

对于第一点，做了一个小实验：使用 Handler.post(message)。如果上述推论成立，那这条消息就永远得不到执行。

直觉告诉我，这个实验是对上述推论的有利反例。果不其然，message 被执行了。。。

重新回看了一遍消息机制的源码，找到了原因。

同步消息屏障只保障下一个异步消息优先执行，且当 View 树遍历任务执行时屏障就被移除了，此时队列中的同步消息就得到了一次执行的机会。

不是有视图在不停重绘，不停抛屏障消息吗？为啥同步消息还有机会执行？

因为消息队列是按时间递增排序的，每次消息入队都需要遵守这个规则，同步消息屏障也不例外。不停抛屏障之间是有间隙的，如果一个同步消息见缝插针地成功入队了，那下一个屏障就排在它后面，取下一条消息时，首先遇到的就是同步消息，而不是屏障消息。

画个图：

假设某一时刻消息队列如图所示，即队列中存在一个同步屏障以及一个异步消息。

当队头的同步消息1被取出之后，下一次取消息时会遇到屏障，此时会越过第二个同步消息直接取它后面的异步消息，异步消息执行的即是 View 树遍历任务，如果异步消息又触发了重绘，则会再抛一个同步消息屏障到队列中，此时屏障消息会被链接到同步消息3后面：

当取下一条消息时，同步2和3会被优先取下，然后才轮到屏障消息。

这解释了为啥 onPause() 在不断有同步消息屏障的情况下仍能被执行。

那为啥 onStop() 没有见缝插针成功呢？

其实不是没插成功，而是压根没插。

Activity 的启动过程是一个 App 进程和 AMS 双向通信，有商有量的过程，下面以 Activity1 启动 Activity2 为例：

App -> AMS：Activity1 告诉 AMS 说，我要启动 Activity2。
AMS -> App：AMS 为 Activity2 创建一些结构，然后告诉 Activity1 说，你可以 onPause 了。
App -> AMS：Activity1.onPause() 执行完毕之后，告诉 AMS 说，我 onPause 完了，起新界面吧。
AMS -> App：AMS 告诉 Activity2 说，你可以执行 onCreate，onStart，onResume 了。
App -> AMS：当 Activity2 执行完 onResume 后，告诉 AMS 说我启动完毕了，请执行后续操作。
AMS -> App：AMS 告诉 Activity1，你可以执行 onStop() 了。

整个过程就好像网络通信，各端在未收到对方的响应之前，不会轻举妄动。

若通信发生中断，则后续流程就进行不下去。上面流程中的第五步是当前问题的关键点。当 Activity2.onResume 执行完后，它会向主线程抛一个 IdleHandler：

 // android.app.ActivityThread.java
public final class ActivityThread extends ClientTransactionHandler {@Overridepublic void handleResumeActivity(IBinder token, boolean finalStateRequest, boolean isForward, String reason) {...// 当启动页执行完 onResume 会向主线程消息队列注册一个 IdleHandlerLooper.myQueue().addIdleHandler(new Idler());}private class Idler implements MessageQueue.IdleHandler {@Overridepublic final boolean queueIdle() {、...// 当 idleHandler 被执行时，通知 AMS 启动新界面已完毕，你可以做后续操作IActivityManager am = ActivityManager.getService();am.activityIdle(a.token, a.createdConfig, stopProfiling);}}
}

IdleHandler 被 MessageQueue 持有，且只有当消息队列空闲，即没有消息时，才会被执行：

// android.os.MessageQueue.java
// 消息队列持有 IdleHandler 列表
private final ArrayList<IdleHandler> mIdleHandlers = new ArrayList<IdleHandler>();
Message next() {for (;;) {synchronized (this) {Message prevMsg = null;Message msg = mMessages;// 遇到同步消息屏障，优先获取异步消息if (msg != null && msg.target == null) {do {prevMsg = msg;msg = msg.next;} while (msg != null && !msg.isAsynchronous());}// 获取消息成功并返回if (msg != null) {...return msg;}...// 当消息队列为空的时候，为 pendingIdleHandlerCount 赋值if (pendingIdleHandlerCount < 0 && (mMessages == null || now < mMessages.when)) {pendingIdleHandlerCount = mIdleHandlers.size();}...}// 仅当 pendingIdleHandlerCount > 0 时，才执行 IdleHanlderfor (int i = 0; i < pendingIdleHandlerCount; i++) {final IdleHandler idler = mPendingIdleHandlers[i];// 执行 IdleHandlerkeep = idler.queueIdle();}...}
}

因为有视图不停地在重绘，即不停的抛同步屏障到消息队列，所以队列永不为空，所以 IdleHandler 永远不会被执行！即启动页无法告知 AMS，我已经启动完毕，那 AMS 自然无法通知上一个界面执行 onStop()。

所有的疑惑都消除了，除了最后一个：“为啥正正好好 10 秒之后 onStop 又调用了？”

因为 AMS 有一个保护机制，如果它和 App 进程双向通信失败，则会延迟 10 秒强制调用上一个界面的 onStop()：

// com.android.server.wm.ActivityRecord.java
final class ActivityRecord extends ConfigurationContainer implements AppWindowContainerListener {void completeResumeLocked() {...// 当启动页 resume 执行完毕后，开启一个超时任务mStackSupervisor.scheduleIdleTimeoutLocked(this);...}
}// com.android.server.wm.StackSupervisor.java
public class ActivityStackSupervisor extends ConfigurationContainer implements DisplayListener,RecentTasks.Callbacks {// 10 秒超时private static final int IDLE_TIMEOUT = 10 * 1000;void scheduleIdleTimeoutLocked(ActivityRecord next) {// 抛一个延迟消息，当该消息被执行时，意味着 onResume 超时发生Message msg = mHandler.obtainMessage(IDLE_TIMEOUT_MSG, next);mHandler.sendMessageDelayed(msg, IDLE_TIMEOUT);}private final class ActivityStackSupervisorHandler extends Handler {@Overridepublic void handleMessage(Message msg) {switch (msg.what) {// 执行超时消息，强制 app 执行 onStopcase IDLE_TIMEOUT_MSG: {activityIdleInternal((ActivityRecord) msg.obj, true);} break;...}}// 强制 app 执行 onStopvoid activityIdleInternal(ActivityRecord r, boolean processPausingActivities) {synchronized (mService) {activityIdleInternalLocked(r != null? r.appToken: null, true/* fromTimeout */,processPausingActivities, null);}}
}

完美，所有的推论都能自圆其说了，总结一下：

盖棺定论：有一个视图在不断地触发重绘，导致主线程消息队列中有源源不断的同步消息屏障，即队列永不为空。这样的话 IdleHandler 永远没有机会执行，而启动页正好是通过 IdleHandler 通知 AMS 启动完成，只有当 AMS 收到通知后，才会触发上一个界面的 onStop。不过 AMS 留了一手，它在通知启动页执行 onResume 后会开启一个 10 秒超时任务，当该任务被执行时，意味着启动页 resume 超时，此时 AMS 会强制通知上一个界面执行 onStop()。

七、修复

现在问题转换成，如何找到那个重绘的视图？

手段3：如果能把 App 某时间段内所有的调用栈都展示出来就有利于找到真凶。

我选择的工具是 AndroidStudio 中的 Profiler（若有其他更好方法，欢迎留言告诉我哈~）。其中的 CPU 标签页可以记录一段时间内所有的方法调用：

点击 Record 就可以进行方法调用的监听，想结束时，点击 Stop。AndroidStudio 会生成一个 trace 文件：

trace 文件的信息量是及其巨大的。可以点击右侧的 Top Down 标签页，然后在搜索框输入 App 包名，就能过滤出自家 App 的方法调用信息了：

被过滤的调用块会高亮。挑选了一块高亮放大查看，之所以选择这块高亮，是因为它是一个异步消息的执行调用链：

放大这个调用链，在末端有一个加粗的调用，这正是自家包名的调用，此处是一个自定义 View 的 onDraw 方法，并且在 onDraw() 中调用了 invalidate()。

直接调转到该自定义 View：

public class CollisionView extends FrameLayout {...@Overrideprotected void onDraw(Canvas canvas) {JniInterface.startWorld(); // JNI 方法1int childCount = getChildCount();for (int i = 0; i < childCount; i++) {View view = getChildAt(i);JniInterface.drawView(view, i); // JNI 方法2}// 凶手invalidate();}
}

该自定义 View 实现重力感应的碰撞效果。

重力感应这个明显的动画，不是能直接用眼睛看到吗？何必费这么大劲来精准定位？因为重力感应的展示取决于一个接口，接口已经下了。但该视图定义在 xml 中，所以不管接口是否返回，它总会被 inflate，即它的 onDraw 一定会被默默地执行。而且刚接手代码，我对该模块的业务一无所知。

仔细端详 onDraw()，发现绘制最终是通过 JNI 调用实现的，并没有用到 canvas。这里的 onDraw + invalidate，只是为了实现无限循环调用两个 JNI 方法。

所以重构方案就是异步绘制：

class CollisionView @JvmOverloads constructor(context: Context, attrs: AttributeSet? = null, defStyleAttr: Int = 0) : FrameLayout(context, attrs, defStyleAttr) {private var refreshJob: Job? = nullprivate val scope = CoroutineScope(SupervisorJob() + Dispatchers.Default)override fun onLayout(changed: Boolean, left: Int, top: Int, right: Int, bottom: Int) {super.onLayout(changed, left, top, right, bottom)JniInterface.updateBounds(measuredWidth, measuredHeight, childCount)val childCount = childCountfor (i in 0 until childCount) {val view = getChildAt(i)val type = view.getTag(R.id.view_body_type) as IntJniInterface.bindBody(view.x, view.y, view.width.toFloat(), view.height.toFloat(), view, i, type)}// 取消上一个异步绘制任务refreshJob?.takeIf { it.isActive }?.cancel()// 开启异步绘制，每 16 毫秒绘制一次refreshJob = countdown(Long.MAX_VALUE, 16) { drawView() }.launchIn(scope)}// 调用 JNI 进行绘制private fun drawView() {JniInterface.startWorld()val childCount = childCountfor (i in 0 until childCount) {val view = getChildAt(i)JniInterface.drawView(view, i)}}// 重力发生变化时，重绘fun onSensorChanged(x: Float, y: Float) {val childCount = childCountfor (i in 0 until childCount) {val view = getChildAt(i)JniInterface.applyLinearImpulse(x, y, view)}}override fun onVisibilityChanged(changedView: View, visibility: Int) {super.onVisibilityChanged(changedView, visibility)// 若不可见，则停止异步绘制，待可见时再开启。if (visibility == View.VISIBLE) {refreshJob?.takeIf { it.isCancelled }?.run {refreshJob = countdown(Long.MAX_VALUE, 16) { drawView() }.launchIn(scope)}} else if (visibility == View.INVISIBLE) refreshJob?.cancel()}init {setWillNotDraw(false)JniInterface.initModel()JniInterface.setDensity(resources.displayMetrics.density)}
}// 后台间隔任务
fun <T> countdown(duration: Long,interval: Long,context: CoroutineContext = Dispatchers.Default,onCountdown: suspend (Long) -> T
): Flow<T> =flow { (duration - interval downTo 0 step interval).forEach { emit(it) } }.onEach { delay(interval) }.onStart { emit(duration) }.flatMapMerge { flow { emit(onCountdown(it)) } }.flowOn(context)

定义了一个顶层方法 countdown()，内部借助于 Kotlin Flow 隐藏了在后台间隔执行任务的细节。并将原先 onDraw() 中的逻辑提取为一个方法，然后通过countdown(Long.MAX_VALUE, 16) { drawView() }实现每隔 16 ms 绘制一次。

同时添加了视图可见性的判断，当视图不可见时通过 Job 取消之前的绘制任务，再次可见时重启。

重构完，把 App 跑起来，当我以为万事大吉的时候，传来噩耗。。。。

如洪水般的 log 并未消退。经历了另一番摸爬滚打之后，定位到另一个问题。。。

主界面由 5 个 tab 组成，其中第一个 tab 包含碰撞动画，重构后若只加载此 tab，Activity 生命周期回调的问题就不再复现了。

其余的 4 个 tab 中有 2 个 tab 单独加载时，还是会不断触发重绘。再次拿出 Profiler 大法，发现了一个超级奇怪的现象：

主线程的调用栈就像缝纫机一样，异常整齐。然后全局搜索 invalidate，无果。。。

接着搜索 requestLayout，无果。。。

再接着搜索 request，找到了端倪：

View 树遍历的调用栈是这样的：

ViewRootImpl.performTraversals() ->

ViewRootImpl.dispatchApplyInsets() ->

ViewGroup.dispatchApplyWindowInsets() ->

ViewPager.onApplyWindowInsets() ->

View.requestFitSystemWindows() ->

首页的各个 tab 是一个 Fragment，它们通过 ViewPager 管理。

接着搜索 draw，又有新的发现：

出问题的那两个 tab 有一个共同特点就是都是用了 CoordinateLayout + AppbarLayout + CollapsingToolbarLayout

然后做了一些实验，最终发现问题是CollapsingToolbarLayout + ViewPager导致的。把其中任何一个换掉，问题就解决了。

从 Profiler 看，感觉问题好像是 CollapsingToolbarLayout + ViewPager 这个组合在适配系统屏幕的时候，会不停的发生重绘。

其中 CollapsingToolbarLayout 的版本是 com.google.android.material:material:1.1.0，而 ViewPager 是 androidx.viewpager:viewpager:1.0.0

根本原本可能还得花点时间才能定位到，为了快速解决问题，这次先把 CollapsingToolbarLayout 换掉，通过自定义控件实现相同的效果。

不知道有遇到过类似问题的朋友，你们是如何解决的？

总结

Activity 生命周期的超时是由于主线程消息队列没有空闲导致的，即 IdleHandler 永远得不到执行。原因是多种多样的，比如主线程耗时操作、主线程消息数量爆炸。当前 case 是因为视图不断触发重绘，无穷无尽地向主线程抛同步消息屏障导致的。
Android 系统对于 Activity 生命周期超时有一个兜底策略，当启动 Activity 的 onResume() 执行一个延迟 10 秒的消息，当消息被执行时，表示超时发生，此时会强制执行前一个 Activity 的 onStop()。
Looper.getMainLooper().setMessageLogging()和Looper.getMainLooper().dump()是排查消息队列问题的利器。前者用于打印每一条被处理的消息，后者用于打印某一时刻消息队列的快照。
AndroidStudio 中 Profiler 工具的 CPU 标签页是排查“异常调用”的利器。它可以将某段时间内所有的方法调用栈都展示出来。

Activity.onStop() 延迟10秒？堪称精彩绝伦的排查历程相关推荐

进入游戏后如何回到计算机界面,玩LOL胜利后点击“继续游戏”要等个将近10秒才能回到结算界面，请问是怎么回事？...
玩LOL胜利后点击"继续游戏"要等个将近10秒才能回到结算界面,请问是怎么回事?以下文字资料是由(历史新知网www.lishixinzhi.com)小编为大家搜集整理后发布的内容, ...
单片机设置12分频c语言,AT89C51单片机,如何实现延迟一秒
满意答案爱在身边lovely 2013.09.07 采纳率:59% 等级:12 已帮助:7408人其实可以用C语言实现的,先要定义好定时器的初值不管你使用多大的晶振,使用51单片机,一般都 ...
php延迟2秒执行,php延时几秒后搜索
sleep() 函数延迟执行当前脚本若干秒. 注释:如果指定秒数是负数,该函数将抛出一个错误. (推荐学习:PHP视频教程) usleep()函数是把调用该函数的线程挂起一段时间,单位是微秒(百万分之 ...
诚之和:JavaScript setTimeout() – 延迟 N 秒的 JS 计时器
你有没有想过是否有一种方法可以让你的 JavaScript 代码延迟几秒钟?在本文中,我将setTimeout()通过代码示例解释该方法是什么以及它与setInterval(). 什么是setTime ...
个税新政来临，HR如何10秒速算薪酬？
新个税法改革后,受益方无疑是每一位打工人!但对于企业HR们却意味着要更新薪酬算法.如何正确高效计算应扣缴的个税,依旧是企业人事部门的痛点. 面对长长的人员基本表,挨个拉取基本信息,计算上月社保.公积金 ...
EasyDSS点播H.265格式的MTS文件，视频前10秒无法播放该如何解决？
互联网视频云服务EasyDSS视频直播点播平台可为用户提供专业.稳定的直播推流.点播.转码.分发和播放服务,全面满足超低延迟.超高画质.超大并发访问量的要求.平台可支持HTTP.HLS.RTMP等播出 ...
Activity onDestroy延迟回调
前端时间工作的时候遇到了两个奇怪的问题: 使用百度步行导航的时候,开启导航后立即退出,再次进入的时候就会黑屏: 使用度小满支付的时候,当支付成功后页面一直显示loading,过了10s左右才恢复正常. ...
微软Windows 7实现10秒启动的背后
实际上,早在Windows 7处于M3阶段的时候,微软就对Windows 7的表现非常自信.2009年11月初,微软展示了Windows Vista和Windows 7 M3之间的速度差异,结果表明, ...
自动驾驶汽车撞死行人前的10秒，将行人识别为汽车和“其他”，美国官方公布Uber案细节...
晓查发自凹非寺量子位报道 | 公众号 QbitAI 全球首起自动驾驶汽车撞死行人的事故已经过去一年半,事故的调查也已告一段落,今年3月,肇事方Uber被美国法院判决无罪. 就在所有人都几乎要 ...

Activity.onStop() 延迟10秒？堪称精彩绝伦的排查历程

前言