Activity.onStop() 延迟10秒?检测、定位、修复它!

本文涉及的产品
日志服务 SLS,月写入数据量 50GB 1个月
简介: Activity.onStop() 延迟10秒?检测、定位、修复它!

引子


线上 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: Long
    get() = 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 {
    // 和主线程消息队列关联的 Handler
    final 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 {
    // 持有 Printer
    private 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卡顿真的是因为”掉帧“?


若 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() {
    @Override
    public 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:界面中有视图在无限循环地重绘,以至于前一个同步消息屏障被移除后,一个新屏障又立马被添加到队列中,导致同步消息永远无法被执行。(这个推论还是有问题,请往下看)


疑团重重 -> 盖棺定论


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


  1. 只要有视图不停重绘,同步消息永远无法被执行??


  1. 同样是通过消息机制回调生命周期方法,为啥 onPause() 执行了,而 onStop() 没有?


  1. 为啥 onStop() 总是过 10 秒之后被执行??


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


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


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


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


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


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

画个图:


image.png


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


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


image.png


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


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


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


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


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


image.png


  1. App -> AMS:Activity1 告诉 AMS 说,我要启动 Activity2。


  1. AMS -> App:AMS 为 Activity2 创建一些结构,然后告诉 Activity1 说,你可以 onPause 了。


  1. App -> AMS:Activity1.onPause() 执行完毕之后,告诉 AMS 说,我 onPause 完了,起新界面吧。


  1. AMS -> App:AMS 告诉 Activity2 说,你可以执行 onCreate,onStart,onResume 了。


  1. App -> AMS:当 Activity2 执行完 onResume 后,告诉 AMS 说我启动完毕了,请执行后续操作。


  1. AMS -> App:AMS 告诉 Activity1,你可以执行 onStop() 了。


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


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


// android.app.ActivityThread.java
public final class ActivityThread extends ClientTransactionHandler {
    @Override
    public void handleResumeActivity(
        IBinder token, boolean finalStateRequest, boolean isForward, String reason) {
        ...
        // 当启动页执行完 onResume 会向主线程消息队列注册一个 IdleHandler
        Looper.myQueue().addIdleHandler(new Idler());
    }
    private class Idler implements MessageQueue.IdleHandler {
        @Override
        public 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 时,才执行 IdleHanlder
        for (int i = 0; i < pendingIdleHandlerCount; i++) {
            final IdleHandler idler = mPendingIdleHandlers[i];
            // 执行 IdleHandler
            keep = 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 {
        @Override
        public void handleMessage(Message msg) {
            switch (msg.what) {
                // 执行超时消息,强制 app 执行 onStop
                case IDLE_TIMEOUT_MSG: {
                    activityIdleInternal((ActivityRecord) msg.obj, true);
                } break;
                ...
            }
        }
        // 强制 app 执行 onStop
        void 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 标签页可以记录一段时间内所有的方法调用:


image.png


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


image.png


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


image.png


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


image.png


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


直接调转到该自定义 View:


public class CollisionView extends FrameLayout {
    ...
    @Override
    protected void onDraw(Canvas canvas) {
        JniInterface.startWorld(); // JNI 方法1
        int 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? = null
    private 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 = childCount
        for (i in 0 until childCount) {
            val view = getChildAt(i)
            val type = view.getTag(R.id.view_body_type) as Int
            JniInterface.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 = childCount
        for (i in 0 until childCount) {
            val view = getChildAt(i)
            JniInterface.drawView(view, i)
        }
    }
    // 重力发生变化时,重绘
    fun onSensorChanged(x: Float, y: Float) {
        val childCount = childCount
        for (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 大法,发现了一个超级奇怪的现象:


image.png


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


接着搜索 requestLayout,无果。。。


再接着搜索 request,找到了端倪:


image.png


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


ViewRootImpl.performTraversals() ->


ViewRootImpl.dispatchApplyInsets() ->


ViewGroup.dispatchApplyWindowInsets() ->


ViewPager.onApplyWindowInsets() ->


View.requestFitSystemWindows() ->


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


接着搜索 draw,又有新的发现:


image.png


出问题的那两个 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 标签页是排查“异常调用”的利器。它可以将某段时间内所有的方法调用栈都展示出来。


推荐阅读


读源码长知识 | Android卡顿真的是因为”掉帧“?


相关实践学习
日志服务之使用Nginx模式采集日志
本文介绍如何通过日志服务控制台创建Nginx模式的Logtail配置快速采集Nginx日志并进行多维度分析。
目录
相关文章
|
测试技术 程序员 C++
iOS:项目中无用类检测和无用图片检测汇总
在涉及到项目大改版,或者涉及到某个功能模块大变更,就会涉及到图片废弃和文件废弃的情况。 但是这时候就会遗留下一个很大的问题,没有将废弃的、无用的文件类或资源删除干净。而这次需要对工程代码的无用资源和无用文件进行删除处理,感触颇多,故在此笔记。 首先,感觉很多人的代码习惯还是恶待提高。比如我发现一些人的代码操作习惯,从好到次,可以大略分以下情况
1277 0
iOS:项目中无用类检测和无用图片检测汇总
|
1月前
|
SQL 前端开发 Linux
如何定位前后端的BUG
如何定位前后端的BUG
37 2
|
2月前
|
Java 测试技术 Android开发
Android性能测试——发现和定位内存泄露和卡顿
本文详细介绍了Android应用性能测试中的内存泄漏与卡顿问题及其解决方案。首先,文章描述了使用MAT工具定位内存泄漏的具体步骤,并通过实例展示了如何分析Histogram图表和Dominator Tree。接着,针对卡顿问题,文章探讨了其产生原因,并提供了多种测试方法,包括GPU呈现模式分析、FPS Meter软件测试、绘制圆点计数法及Android Studio自带的GPU监控功能。最后,文章给出了排查卡顿问题的四个方向,帮助开发者优化应用性能。
167 4
Android性能测试——发现和定位内存泄露和卡顿
|
6月前
|
数据安全/隐私保护
硬盘坏道如何检测和修复?
本文介绍了硬盘坏道的概念,包括逻辑坏道和物理坏道的区别,并提供了使用DiskGenius检测和修复坏道的步骤。当硬盘出现坏道且包含重要数据时,应立即备份数据,使用数据恢复软件,或在严重情况下寻求专业帮助。保护和恢复数据是应对硬盘坏道的关键。
|
6月前
|
弹性计算 运维 Ubuntu
自动检测并处理系统更新
【4月更文挑战第30天】
123 0
如何检查视频画面延迟的时间
做视频通讯的朋友,画面延迟,就是要经常测试的事情。那么怎样测试延迟呢?
463 0
|
SQL BI 数据库
记一次bug分析定位过程
其实很多时候,我们在测试过程中发现的很多bug,并不是由于开发人员编码能力不好,或者粗心大意造成,而是在项目开发实施过程中,没有遵循一些必要的项目流程,没有充分认识到质量的重要性;如果能做好这方面的工作,关注流程,而不是喊口号,人人重视质量,人人为结果负责,那么,会有很多问题、不只是bug,都将“被扼杀在摇篮里”......
记一次bug分析定位过程
|
消息中间件 存储 设计模式
Android卡顿优化 | 自动化卡顿检测方案与优化(AndroidPerformanceMonitor / BlockCanary)
Android卡顿优化 | 自动化卡顿检测方案与优化(AndroidPerformanceMonitor / BlockCanary)
|
Android开发 开发者
Android系统是如何计算应用启动耗时的?能否更精准定位性能瓶颈呢?
Android系统是如何计算应用启动耗时的?能否更精准定位性能瓶颈呢?
Android系统是如何计算应用启动耗时的?能否更精准定位性能瓶颈呢?
|
监控 算法 Java
【Android 逆向】Android 逆向方法 ( 静态逆向解析 | 函数调用分析 | 动态运行跟踪 | 运行日志分析 | 文件格式解析 | 敏感信息分析 | 网络信息监控 | 环境伪装模拟 )
【Android 逆向】Android 逆向方法 ( 静态逆向解析 | 函数调用分析 | 动态运行跟踪 | 运行日志分析 | 文件格式解析 | 敏感信息分析 | 网络信息监控 | 环境伪装模拟 )
395 0