Categories
程式開發

另类 BadTokenException 问题分析和解决


背景:

对于 Android 开发者来说,BadTokenException 问题都有直接或间接的遇到,尤其是在使用 Toast 和 Dialog 过程,因为这两类场景的展示过程都发生在异步,如果在展示之前,主线程消息耗时过多导致服务端(SystemServer)判定超时或 Dialog 依赖的 Activity 被销毁后,就可能发生类似异常,网上关于这两类问题的介绍和解决方案有很多,不在此展开。

这里我们主要分析所有 App 都会遇到的另一类 BadTokenException 问题,这类问题会在 App 体量变大之后,暴露的愈发明显,如下图这类问题在公司内部很多产品都是 TopCase。

  • Crash 堆栈表现如下:

另类 BadTokenException 问题分析和解决 1

流程分析:

和 Toast 和 Dialog 场景的 BadToken 一样,在开始分析该类问题之前,首先要弄清楚 Activity 的这个 Token 是怎么产生的,它的作用是什么,都会在哪些场景用到?

Token 释义及使用场景

Token,顾名思义就是记号,识别号,既然是一个记号,那么就需要保证全局唯一,才便于整个系统去识别和管理。翻看源码可以发现,这个 Token 并不是在客户端进程生成的;

另类 BadTokenException 问题分析和解决 2

既然不是客户端那么就是在服务端了,那么 Activity 对应的这个 Token 是怎么生成的呢?

  • 启动 Activity 之前系统端 AMS 会创建 ActivityRecord,并在构造函数内部实例化了一个 Token,这个 token 保证了唯一性,从而保证了 Activity 在 AMS 端的唯一标识,包括 WMS 及其它服务都基于这个唯一标识进行信息同步和区分:

另类 BadTokenException 问题分析和解决 3

  • 服务端 AMS 在通知客户端实例化 Activity 过程,会传入 Token 标识给客户端进程,及后期便于将服务端与客户端(ActivityRecord 与 ActivityClientRecord)进行同步管理:

另类 BadTokenException 问题分析和解决 4

  • 同时 AMS 在创建完 ActivityRecord 之后,也要通知 WMS 去为当前 Activity 创建一个 WindowToken,便于将当前的 Activity 与之对应的 Window 进行关联,依然传入 Token 标识做 Key 映射,调用过程:

另类 BadTokenException 问题分析和解决 5

在 WMS 内部,会根据传入的 appToken 去查找是否已经创建过 WindowToken,如果没有则实例化一个 WindowToken,并将 token 作为标识。

另类 BadTokenException 问题分析和解决 6

  • 在回到客户端,App 进程根据 Token 作为 key 将当前的 ActivityClientRecord 与 token 建立映射,存入 map 表中。

另类 BadTokenException 问题分析和解决 7

在搞清楚 token 的由来和使用场景之后,下面就进入正题,看一下为啥刚创建的 token 为啥,就提示 Wms 端被移除了呢?那又是怎么移除的呢?

Activity 的 Destory 过程:

Activity 的生命周期,主要包括下面几个过程:Create,Pause,Stop,Destory;进一步分析系统源码可以知道,在 AMS 向客户端进程对应 Activity 发送了 Destory 通知并完成或发送之后一直没有执行,发送超时之后,系统服务 AMS 才会通知 WMS 将当前 Activity 的 Window 移除掉;详见:ActivityStack.java

另类 BadTokenException 问题分析和解决 8

回到当前问题,从进程崩溃现场可知,主线程正在创建 Activity(LaunchActivity),此时主线程消息队列所有消息都被 Block,没有机会执行 onDestory,那么猜测有一种可能,即系统在向客户端进程发送 scheduleDestory 之后,触发了 Timeout,从而在服务端强制触发了 Destory 操作并将 WindowToken 移除(感觉系统太不负责任了)。

但是受限于系统对 App 权限管控,无法从 App 层面获取系统 event 日志,否则从 event 日志可以清楚的看到 activity 生命周期的切换过程。那么从 App 层是否有其它办法确认系统是否已经对当前 Activity 执行了 Destory 请求呢?答案是有的。

消息调度:

我们之前为了更好的分析 ANR 问题,并针对 App 因权限获取信息不足,上线了主线程消息调度监控,简单来说就是对发生 ANR 问题之前一段时间,耗时较长的调度消息进行监控并统计,目的是为了更好的监控 ANR 发生之前一段时间主线程的状态,包括:

  1. 主线程都执行了哪些耗时的消息
  2. 当前正在消息已处理时长
  3. 获取缓存在消息队列未被调度的消息及其被 pending 时长

参考下图:

另类 BadTokenException 问题分析和解决 9

有了上述消息调度监控,我们便可以清晰看到 pending 消息队列是否有我们预期的未调度消息,如: H.DESTROY_ACTIVITY 。我们将 ANR 的消息调度监控扩展到了 Crash 场景,以便于分析这类时序类问题,提供有更多更有效的参考信息。

问题分析:

有了上面大量的知识铺垫和信息扩展,直接结合下面问题实例进行分析,通过我们 Crash 画像可以看到:当前进程启动时长为 22S,并处于后台。为啥处于后台?基本是用户刚打开这个应用,由于其他原因,如来电?语音电话?Home 键?将其切回到后台(可以思考一下如果处于前台会不会有该类问题?)但是当前应用状态仍处于 LaunchActivity 阶段,后台场景也为该问题埋下伏笔。

另类 BadTokenException 问题分析和解决 10

我们拿到了当前 Case 对于的消息调度历史监控数据和 Pending 队列的数据,可以看到当前正在执行的消息正是 HandleLaunchActivity,和 Crash 堆栈现场问题,再看当前消息调度耗时已超过 8S,属于非正常启动

 "current_message": {
                "currentMessageCost": 8454,   // 当前消息耗时超过8S
                "currentMessageCpu": 4120,
                "currentTick": 27,
                "message": "u003eu003eu003eu003eu003e Dispatching to Handler (android.app.ActivityThread$H) {17b8b5a} null: 100"
        },

再进一步搜索消息队列,查看消息队列是否有未处理的 PAUSE_ACTIVITY,及关键的 DESTROY_ACTIVITY 消息,在 pending 消息队列中,找到了与当前正在创建 Activity 对于的 Destory 消息对象( “obj”:“[email protected] ),并且该消息在消息队列 pending 时间已经超过 19S!!!已超过了服务端 AMS 请求 Activity.destory 设置的 10S 超时等待,也就是说服务端已经在发生了 timeOut,并将当前 Activity 及 Token 强制移除;

"pending_messages": [
{
"arg1": 1,
    "arg2": 0,
    "id": 10,
    "obj": "[email protected]", //该对象主线程正在创建的Activity对象里面的ActivityToken
    "target": "Handler (android.app.ActivityThread$H) {17b8b5a}",
    "what": 109,   // 系统已经向客户端发了Destory消息,指挥系统测会去销毁WMS内部维护的WindowStatToken。
    "when": -19845  //发送时间已经长达19S+,这段时间服务端早把对应ActivityToken对应的WindowStat给移除了
},
{
"arg1": 0,
    "arg2": 0,
    "callback": "[email protected]",
    "id": 11,
    "target": "Handler (android.os.Handler) {6e8ddb4}",
    "what": 0,
    "when": -18708
},
    ]

经过上面的分析,并结合消息调度监控及直接数据,我们该类问题有了一个比较清晰的流程,即:在应用退到后台,因为设备环境变化,如 pending Stop Activity 过多,或横竖屏变化,导致服务端 AMS 主动向当前 Activity 发送 Destory 请求,并设置超时监听,如果请求顺利完成,会通知 AMS 并接下来通知 WMS 移除 windowToken,但是如果客户端返回过晚,或没有来得及执行(如当前 BadCase),那么将会在 AMS 端触发 Timeout,强行通知 WMS 移除 windowToken,但是客户端并不知道当前 Activity 在服务端对应的 Token 已经被移除,继续按照正常流程向 WMS 发送 addView 请求时,被 WMS 抛出 BadToken 异常,整个流程如下:

另类 BadTokenException 问题分析和解决 11

分析结论:

综上分析,这类问题主要发生在后台场景,即:Activty 启动过程被用户切换到后台,但因创建 Activity 过程出现 BadCase 导致耗时较长,叠加一些系统环境改变和超时机制,导致系统向当前 Activity 强制发起 Stop 或 Destory 操作,进一步超时后,服务端 AMS 将 WMS 侧的 WindowToken 移除。

从问题分布来看,耗时问题严重的 Activity 实例化过程更容易触发这类问题,如存在 IPC 调用,尽管本地测试 IPC 调用耗时很少,但是到了线上,各种复杂的用户场景不能保证每次 IPC 调用都是高效的,这就可能出现某次初始化过程很久,用户不愿等,退到后台后再遇到系统环境的一些变化,一定概率发生上述问题,如头条内部的一个业务 Activity,贡献了这类问题 90%以上崩溃量。

解决方案:

在分析了问题原因之后,我们再来说说该如何解决或规避此类问题,毕竟 Crash 问题还是很影响用户体验的。解决该类问题主要有 2 个思路:一个是从正面解决,即优化 LaunchActivty 期间对应业务耗时问题,提高性能稳定性,减少 IO,IPC,资源同步等等;部分业务逻辑异步化;将部分数据缓存处理,将会大大减少该类问题发生;

但是对应一个复杂的 App 来说,很难做的彻底,并且随着业务迭代,可能这类问题还会死灰复燃,另一个角度是:对于该类问题进行兜底,以将影响降至最低。

业务侧兜底:

重载部分问题 Activity 的 onResume 方法,在 Activity 第一次执行 onResume 时,判断一下当前 Activity 是否处于后台以及本次 onCreate 到 onResume 耗时是否过长,如果满足这 2 个条件,那么有一定概率触发此类问题;可以在此 Activity 的 onResume 调用结束处,判断消息队列缓存是否已经存在当前 Activity 的 H.DESTROY_ACTIVITY,如果有该消息,则说明 AMS 已经将 WMS 缓存的 windowToken 移除,此时可在客户端主动调用当前 Activity 的 finish 接口,将 Activity 内部的 mFinished 置为 True

另类 BadTokenException 问题分析和解决 12

在 performResumeActivity 之后,系统在 addView 之前,会进行一些状态判断,其中就包括 mFinished 对象,而此时 mFinished 可能已经被我们主动置为 True,因此即可跳过 PeformResumeActivity 结束后的 wm.addView 逻辑,避免 Crash 问题发生;

final void handleResumeActivity(IBinder token,
                                boolean clearHide, boolean isForward, boolean reallyResume, int seq, String reason) {
    ActivityClientRecord r = mActivities.get(token);
    ....
    // TODO Push resumeArgs into the activity for consideration
    r = performResumeActivity(token, clearHide, reason);
    // 主动发出finish之后,当前a.mFinished则被标记为true,内部逻辑直接跳过。
    if (r.window == null && !a.mFinished && willBeVisible) {
        r.window = r.activity.getWindow();
        View decor = r.window.getDecorView();
        decor.setVisibility(View.INVISIBLE);
        ViewManager wm = a.getWindowManager();
        WindowManager.LayoutParams l = r.window.getAttributes();
        a.mDecor = decor;
    ....
        if (a.mVisibleFromClient) {
            if (!a.mWindowAdded) {
                a.mWindowAdded = true;
                wm.addView(decor, l);  //在此处与WMS IPC通信过程发生异常
            }
        }
}

通用解决方案:

除了上面提到的指定业务侧进行兜底之外,还有一种方案可以业务无侵入的方式进行兜底解决,这样做的优势在于大大减少业务的耦合,无需业务适配,即:通过代理 ActivityManager 去监听 willActivityBeVisible 调用,并在监听该接口调用过程去判断当前 Token 在服务侧 AMS 是否存在;如果不存在则说明服务端 AMS/WMS 已经销毁(移除)当前 Activity 的 Token 对象,同理在此主动调用当前 Token 对应 Activity 的 finish()请求,之后相关 addView 相关逻辑不被执行,以解决此类问题。

final void handleResumeActivity(IBinder token, boolean clearHide, boolean isForward, boolean reallyResume, int seq, String reason) {
    .......
    // TODO Push resumeArgs into the activity for consideration
    r = performResumeActivity(token, clearHide, reason);
    if (r != null) {
        final Activity a = r.activity;
        ......
        boolean willBeVisible = !a.mStartedActivity;
        if (!willBeVisible) {
            try {
                willBeVisible = ActivityManager.getService().willActivityBeVisible(
                        a.getActivityToken());
            } catch (RemoteException e) {
                throw e.rethrowFromSystemServer();
            }
        }
        //如果调用了finish,则a.mFinished遍历被置为True,则addView将不会被执行,后续相关逻辑也被跳过
        if (r.window == null && !a.mFinished && willBeVisible) {
            if (a.mVisibleFromClient) {
                if (!a.mWindowAdded) {
                    a.mWindowAdded = true;
                    wm.addView(decor, l); //异常在这里发生
                } else {
                }
            }
           ......
        }
    }
}

更多问题

后续我们将分享更多 Android 系统本身及厂商定制引起的稳定性问题及解决方案,欢迎大家继续关注。

本文转载自公众号字节跳动技术团队(ID:toutiaotechblog)。

原文链接

https://mp.weixin.qq.com/s/DmN9sN_MdugpVm73vnVqww