Android疑难杂症之TimeoutException

1.分析原因

在android开发中经常会到一些即使看了堆栈也无法快速定位的问题，因为这些堆栈几乎都是系统代码，并无业务代码，而且发生crash打印的堆栈也不一定是这个地方导致的。例如我们今天要讨论的java.util.concurrent.TimeoutException，我们这里能查询到一个上报的堆栈如下：

• java.util.concurrent.TimeoutException: android.content.res.AssetManager.finalize() timed out after 10 seconds
• android.content.res.AssetManager.destroy(Native Method)
• android.content.res.AssetManager.finalize(AssetManager.java:591)
• java.lang.Daemons$FinalizerDaemon.doFinalize(Daemons.java:250)
• java.lang.Daemons$FinalizerDaemon.runInternal(Daemons.java:237)
• java.lang.Daemons$Daemon.run(Daemons.java:103)
• java.lang.Thread.run(Thread.java:764)

可以看到这些都是系统的堆栈，我们也无法快速定位到业务中到底是哪里导致了这个crash，只能从给出的堆栈知道是在系统回收资源AssetManager进行析构时超时导致的异常。

上网查询后发现，这其实已经算是一个比较普遍的问题，而且大多发生在OPPO和360手机中，究其原因：

• Android在启动后会创建一些守护线程，其中涉及到该问题的有两个，分别是FinalizerDaemon和FinalizerWatchdogDaemon.

• 对FinalizerDaemon析构守护线。对于重写了成员函数finalize的对象，当它们被GC决定要被回收时，并不会马上被回收，而是被放入到一个队列中，等待FinalizerDaemon守护线程去调用它们的成员函数finalize后再被回收。

• FinalizerWatchdogDaemon析构监听守护线程，用来监控FinalizerDaemon线程的执行。一旦监测到那些重写了finalize的对象在执行成员函数finalize时超出一定时间，那么就会退出VM。

  从上面的分析知道，如果FinalizerDaemon进行对象析构时超过了MAX_FINALIZE_NANOS（默认10s，各个Rom厂商很可能会更改这个参数。例如OPPO很多机器上这个参数被改成了120s），FinalizerWatchdogDaemon进行就会抛出TimeoutException

  Daemons.java#FinalizerWatchdogDaemon

private static void finalizerTimedOut(Object object) {
    // The current object has exceeded the finalization deadline; abort!
    String message = object.getClass().getName() + ".finalize() timed out after "+ (MAX_FINALIZE_NANOS / NANOS_PER_SECOND) + " seconds";
    Exception syntheticException = new TimeoutException(message);
    ……
}

10s的超时其实是很大的一个值，一般的析构方法的执行时间很难超过这个数。我们大致推断发生这种crash的特点：

• 从数据来看，崩溃都是应用处于后台不可见的情况下发生
• 崩溃时应用已经被长时间使用

从Stack Overflow上找到了一个相对比较合理的出现场景：

• 当你的应用处于后台，有对象需要释放回收内存时
• 记录一个start_time，然后FinalizerDaemon开始析构AssetManager对象
• 在这个过程中，设备突然进入了休眠状态，析构执行被暂停
• 当过了一段时间，设备被唤醒，析构任务被恢复，继续执行，直至结束
• 在析构完成后，得到一个end_time
• FinalizerWatchdogDaemon对end_time与start_time进行差值并与MAX_FINALIZE_NANOS比较，发现超过了MAX_FINALIZE_NANOS，于是就抛出了TimeOut异常

可见应用后台执行的时间越长，出现的概率应该就会越大。

2.解决方案

我们上面分析了发生这种TimeOut异常的原因，知道要根治这个问题，还是要合理的编码，特别在涉及到内存分配方面时。那么到底什么才是合理编码，怎么才能合理的申请的内存、复用内存和回收内存呢。这是一个仁者见仁智者见智的事情，也不是我们本文讨论的重点。这里我们提供一种折中的补救措施。就是在我们的应用进程起来后，我们通过反射主动关闭FinalizerWatchdogDaemon线程对析构过程的监听，这样即使FinalizerDaemon 调用对象的finalize进行析构回收超时了，也不会抛出这个TimeOut异常了。

private void stopWatchdogDaemon() {
    GLog.i(TAG, "---stopWatchdogDaemon---");
    try {
        /**
         * 1.获取Daemons$FinalizerWatchdogDaemon的单例实例INSTANCE
         */
        Class clazz = Class.forName("java.lang.Daemons$FinalizerWatchdogDaemon");
        Field field = clazz.getDeclaredField("INSTANCE");
        field.setAccessible(true);
        Object watchDog = field.get(null);
        try {
            /**
             * 2.将Daemon的成员变量thread设置为null
             */
            Field thread = clazz.getSuperclass().getDeclaredField("thread");
            thread.setAccessible(true);
            thread.set(watchDog, null);
        } catch (Throwable throwable) {
            GLog.e(TAG, "set thread null to stop watchDog error, throwable: " + throwable.getMessage());
            try {
                /**
                 * 3.如果2中将thread置null失败，则直接调用Daemon的stop方法
                 */
                Method method = clazz.getSuperclass().getDeclaredMethod("stop");
                method.setAccessible(true);
                method.invoke(watchDog);
            } catch (Throwable error) {
                GLog.e(TAG, "invoke stop method to stop watchDog error, throwable: " + error.getMessage());
            }
        }
    } catch (Throwable throwable) {
        GLog.e(TAG, "get obj to stop watchDog error, throwable: " + throwable.getMessage());
    }
}

上面通过反射首先将FinalizerWatchdogDaemon父类Daemon中的thread置空，如果失败再通过反射调用FinalizerWatchdogDaemon父类Daemon的stop方法继续将成员变量thread置空（如下代码中的1处注释所示），并停止线程（下代码中的2处注释所示）

SDK=28 Daemons.java#Daemon

/**
 * Waits for the runtime thread to stop. This interrupts the thread
 * currently running the runnable and then waits for it to exit.
 */
public void stop() {
    Thread threadToStop;
    synchronized (this) {
        // 1.外部调用置空
        threadToStop = thread;
        thread = null;
    }
    if (threadToStop == null) {
        throw new IllegalStateException("not running");
    }
    // 2.停止线程
    interrupt(threadToStop);
    while (true) {
        try {
            threadToStop.join();
            return;
        } catch (InterruptedException ignored) {
        } catch (OutOfMemoryError ignored) {
            // An OOME may be thrown if allocating the InterruptedException failed.
        }
    }
}

// 3.线程安全的操作
public synchronized void interrupt(Thread thread) {
    if (thread == null) {
        throw new IllegalStateException("not running");
    }
    thread.interrupt();
}

Ps:在6.0之前，当使用stop方法来停止线程时，是一个不安全的操作，可能会存在线程安全问题。如下代码所示

参考

1. AssetManager.finalize() Timed Out After 10 Seconds分析
2. 安卓开发中遇到的奇奇怪怪的问题（三）