【问题标题】:How to handle :java.util.concurrent.TimeoutException: android.os.BinderProxy.finalize() timed out after 10 seconds errors?如何处理 :java.util.concurrent.TimeoutException: android.os.BinderProxy.finalize() 在 10 秒错误后超时?
【发布时间】:2014-07-24 04:03:34
【问题描述】:

我们在GcWatcher.finalize, BinderProxy.finalizePlainSocketImpl.finalize 中看到了许多TimeoutExceptions。其中 90% 以上发生在 Android 4.3 上。我们收到来自 Crittercism 的来自现场用户的报告。

错误是:“com.android.internal.BinderInternal$GcWatcher.finalize() timed out after 10 seconds”的变体

java.util.concurrent.TimeoutException: android.os.BinderProxy.finalize() timed out after 10 seconds
at android.os.BinderProxy.destroy(Native Method)
at android.os.BinderProxy.finalize(Binder.java:459)
at java.lang.Daemons$FinalizerDaemon.doFinalize(Daemons.java:187)
at java.lang.Daemons$FinalizerDaemon.run(Daemons.java:170)
at java.lang.Thread.run(Thread.java:841)

到目前为止,我们还没有运气在内部重现问题或找出可能导致它的原因。

有什么想法会导致这种情况吗? 知道如何调试它并找出应用程序的哪个部分导致这种情况吗? 任何能阐明这个问题的东西都会有所帮助。

更多堆栈跟踪:

1   android.os.BinderProxy.destroy  
2   android.os.BinderProxy.finalize Binder.java, line 482
3   java.lang.Daemons$FinalizerDaemon.doFinalize    Daemons.java, line 187
4   java.lang.Daemons$FinalizerDaemon.run   Daemons.java, line 170
5   java.lang.Thread.run    Thread.java, line 841  

2

1   java.lang.Object.wait   
2   java.lang.Object.wait   Object.java, line 401
3   java.lang.ref.ReferenceQueue.remove ReferenceQueue.java, line 102
4   java.lang.ref.ReferenceQueue.remove ReferenceQueue.java, line 73
5   java.lang.Daemons$FinalizerDaemon.run   Daemons.java, line 170
6   java.lang.Thread.run

3

1   java.util.HashMap.newKeyIterator    HashMap.java, line 907
2   java.util.HashMap$KeySet.iterator   HashMap.java, line 913
3   java.util.HashSet.iterator  HashSet.java, line 161
4   java.util.concurrent.ThreadPoolExecutor.interruptIdleWorkers    ThreadPoolExecutor.java, line 755
5   java.util.concurrent.ThreadPoolExecutor.interruptIdleWorkers    ThreadPoolExecutor.java, line 778
6   java.util.concurrent.ThreadPoolExecutor.shutdown    ThreadPoolExecutor.java, line 1357
7   java.util.concurrent.ThreadPoolExecutor.finalize    ThreadPoolExecutor.java, line 1443
8   java.lang.Daemons$FinalizerDaemon.doFinalize    Daemons.java, line 187
9   java.lang.Daemons$FinalizerDaemon.run   Daemons.java, line 170
10  java.lang.Thread.run

4

1   com.android.internal.os.BinderInternal$GcWatcher.finalize   BinderInternal.java, line 47
2   java.lang.Daemons$FinalizerDaemon.doFinalize    Daemons.java, line 187
3   java.lang.Daemons$FinalizerDaemon.run   Daemons.java, line 170
4   java.lang.Thread.run

【问题讨论】:

  • 没关系,找到它bugzilla.mozilla.org/show_bug.cgi?id=864102 我也可以确认它影响了我们的应用程序,它闻起来像 Google Play 服务问题
  • 抛出错误的那行代码是在 2013 年 6 月 5 日发布的版本 4.3_r1 中引入的。可能是从那时起出现的问题。
  • Android 版本 4.2.2 也开始抛出此异常,因此可能它的源是 google play 更新。
  • @EvelioTarazona 我在一些不使用播放服务的应用程序中有它
  • @ligi 你的堆栈跟踪是一样的吗?

标签: android garbage-collection


【解决方案1】:

完全披露 - 我是前面提到的 TLV DroidCon 演讲的作者。

我有机会在许多 Android 应用程序中检查了这个问题,并与遇到它的其他开发人员讨论了这个问题 - 我们都达成了同一点:这个问题无法避免,只能最小化。

我仔细查看了 Android 垃圾收集器代码的默认实现,以更好地了解引发此异常的原因以及可能的原因。我什至在实验过程中发现了一个可能的根本原因。

问题的根源在于设备“进入睡眠”一段时间 - 这意味着操作系统已决定通过暂时停止大多数用户空间进程并关闭屏幕来降低电池消耗,减少 CPU 周期等。这样做的方式是在 Linux 系统级别上,其中进程在运行中暂停。这可能在正常应用程序执行期间的任何时间发生,但它将在本机系统调用处停止,因为上下文切换是在内核级别完成的。所以 - 这就是 Dalvik GC 加入故事的地方。

Dalvik GC 代码(在 AOSP 站点的 Dalvik 项目中实现)不是一段复杂的代码。我的 DroidCon 幻灯片介绍了它的基本工作方式。我没有介绍的是基本的 GC 循环——收集器有一个要完成(和销毁)的对象列表。底层的循环逻辑可以这样简化:

  1. starting_timestamp,
  2. 删除对象以获取要释放的对象列表,
  3. 释放对象 - finalize() 并在需要时调用原生 destroy()
  4. end_timestamp,
  5. 计算 (end_timestamp - starting_timestamp) 并与 10 秒的硬编码超时值进行比较,
  6. 如果超时 - 抛出 java.util.concurrent.TimeoutException 并终止进程。

现在考虑以下场景:

应用程序在做它的事情时运行。

这不是面向用户的应用程序,它在后台运行。

在此后台操作期间,对象被创建、使用并需要被收集以释放内存。

应用程序不会打扰 WakeLock - 因为这会对电池产生不利影响,而且似乎没有必要。

这意味着应用程序会不时调用 GC。

通常情况下,GC 运行会顺利完成。

有时(很少)系统会决定在 GC 运行过程中休眠。

如果您运行应用程序的时间足够长,并密切监视 Dalvik 内存日志,就会发生这种情况。

现在 - 考虑基本 GC 循环的时间戳逻辑 - 设备可以开始运行,获取 start_stamp,并在系统对象上的 destroy() 本机调用时进入睡眠状态。

当它唤醒并继续运行时,destroy() 将完成,下一个 end_stamp 将是 destroy() 调用所用的时间 + 睡眠时间。

如果睡眠时间过长(超过 10 秒),则会抛出 java.util.concurrent.TimeoutException

我在分析 python 脚本生成的图表中看到了这一点 - 用于 Android 系统应用程序,而不仅仅是我自己监控的应用程序。

收集足够多的日志,你最终会看到它。

底线:

这个问题无法避免 - 如果您的应用在后台运行,您就会遇到它。

您可以通过使用 WakeLock 来缓解问题,并防止设备进入休眠状态,但这完全是另一回事,而且是新的头痛,也许是另一个骗局中的另一个话题。

您可以通过减少 GC 调用来最小化问题 - 降低该场景的可能性(提示在幻灯片中)。

我还没有机会查看 Dalvik 2(a.k.a ART)GC 代码 - 它拥有新的 Generational Compacting 功能,或者在 Android Lollipop 上进行任何实验。

于 2015 年 7 月 5 日添加:

查看此崩溃类型的崩溃报告汇总后,Android 操作系统 5.0+ 版本(带有 ART 的 Lollipop)的这些崩溃似乎仅占此崩溃类型的 0.5%。这意味着 ART GC 更改降低了这些崩溃的频率。

添加于 2016 年 6 月 1 日:

看起来 Android 项目添加了很多关于 GC 在 Dalvik 2.0(又名 ART)中如何工作的信息。

您可以在此处阅读 - Debugging ART Garbage Collection

它还讨论了一些工具来获取有关您应用的 GC 行为的信息。

向您的应用程序进程发送 SIGQUIT 实质上会导致 ANR,并将应用程序状态转储到日志文件以供分析。

【讨论】:

  • 就我而言,我还计划通过寻找减少后台运行的代码量/时间的方法来尝试缓解这种情况。感谢您对该主题的研究。
  • 删除应用中的任何后台处理将大大有助于减少问题。
  • 不管怎样,这仍然发生在 Marshmallow (6.0.1) 中。也就是说,我只收到过一次这个错误。所以这似乎不是一个大问题。感谢您的详尽解释。
  • 一段时间后,我有一个明显的印象,在操作系统中修复这个问题是非常有问题的,需要谷歌和原始设备制造商之间的合作。我预计这不会很快得到解决。
  • 我正在使用唤醒锁,但在 Android 4.4.2 上仍然遇到此问题。我的应用程序有一些后台操作,但主要设计为在安装充电电缆的情况下全天工作。有什么不同的方法可以缓解这个问题吗?
【解决方案2】:

我们使用 Crashlytics 在整个应用程序中不断看到这一点。崩溃通常发生在平台代码中。小样本:

android.database.CursorWindow.finalize() 10 秒后超时

java.util.regex.Matcher.finalize() 10 秒后超时

android.graphics.Bitmap$BitmapFinalizer.finalize() 10 秒后超时

org.apache.http.impl.conn.SingleClientConnManager.finalize() 10 秒后超时

java.util.concurrent.ThreadPoolExecutor.finalize() 10 秒后超时

android.os.BinderProxy.finalize() 10 秒后超时

android.graphics.Path.finalize() 10 秒后超时

发生这种情况的设备绝大多数(但不完全是)三星制造的设备。这可能只是意味着我们的大多数用户都在使用三星设备;或者,它可能表明三星设备存在问题。我不太确定。

我想这并不能真正回答您的问题,但我只是想强调这似乎很常见,并且并非特定于您的应用程序。

【讨论】:

  • Android 5.0.1 版本也会出现这种情况,而且似乎并不局限于三星设备。它发生在 Nexus 6 上。
  • 我在 android 4.4.4 上遇到了这个问题,设备由 XIAOMI 制造
  • 只是想插播一下,我们在三星平板电脑上看到了大多数此类崩溃。不确定三星在平板电脑处理后台应用的方式上有何不同。
  • 我在 android 4.4.4 上遇到了这个问题。华为制造的设备。
  • 如果我在 android 5.0.2 三星设备上使用泄漏金丝雀库后,我的应用程序会崩溃。如果我禁用库初始化,应用程序就可以正常工作。
【解决方案3】:

我找到了一些关于这个问题的幻灯片。

http://de.slideshare.net/DroidConTLV/android-crash-analysis-and-the-dalvik-garbage-collector-tools-and-tips

在这张幻灯片中,作者告诉我们,如果堆中有很多对象或巨大的对象,这似乎是 GC 的问题。该幻灯片还包括对示例应用程序的引用和用于分析此问题的 python 脚本。

https://github.com/oba2cat3/GCTest

https://github.com/oba2cat3/logcat2memorygraph

此外,我在评论 #3 中发现了一个提示:https://code.google.com/p/android/issues/detail?id=53418#c3

【讨论】:

    【解决方案4】:

    我们通过停止FinalizerWatchdogDaemon 解决了这个问题。

    public static void fix() {
        try {
            Class clazz = Class.forName("java.lang.Daemons$FinalizerWatchdogDaemon");
    
            Method method = clazz.getSuperclass().getDeclaredMethod("stop");
            method.setAccessible(true);
    
            Field field = clazz.getDeclaredField("INSTANCE");
            field.setAccessible(true);
    
            method.invoke(field.get(null));
    
        }
        catch (Throwable e) {
            e.printStackTrace();
        }
    }
    

    您可以在应用程序的生命周期中调用该方法,例如attachBaseContext()。 出于同样的原因,您也可以指定手机的制造商来解决问题,这取决于您。

    【讨论】:

    • 对我们不起作用,我不明白为什么。代码无异常完成,但我们仍会在 Crashlytics 报告和 Google Play 控制台中收到这些问题。
    【解决方案5】:

    这里有一个来自滴滴的有效解决方案来解决这个问题,由于这个bug很常见而且很难找到原因,看起来更像是一个系统问题,为什么我们不能直接忽略它?当然可以忽略它,这里是示例代码:

    final Thread.UncaughtExceptionHandler defaultUncaughtExceptionHandler = 
            Thread.getDefaultUncaughtExceptionHandler();
    Thread.setDefaultUncaughtExceptionHandler(new Thread.UncaughtExceptionHandler() {
        @Override
        public void uncaughtException(Thread t, Throwable e) {
            if (t.getName().equals("FinalizerWatchdogDaemon") && e instanceof TimeoutException) {
            } else {
                defaultUncaughtExceptionHandler.uncaughtException(t, e);
            }
        }
    });
    

    通过设置一个特殊的默认未捕获异常处理程序,应用程序可以更改那些已经接受系统提供的任何默认行为的线程处理未捕获异常的方式。当从名为FinalizerWatchdogDaemon 的线程抛出未捕获的TimeoutException 时,此特殊处理程序将阻塞处理程序链,不会调用系统处理程序,因此将避免崩溃。

    通过实践,没有发现其他不良影响。 GC 系统仍在工作,超时会随着 CPU 使用率的降低而缓解。

    更多详情见:https://mp.weixin.qq.com/s/uFcFYO2GtWWiblotem2bGg

    【讨论】:

    • 如何使用这个来克服异常?
    【解决方案6】:

    广播接收器在 10 秒后超时。可能您从广播接收器执行异步调用(错误),而 4.3 实际上检测到它。

    【讨论】:

    • 检测它似乎没用,也没有告诉你足够多的信息。让我们知道哪个广播会很好。
    • 如果我错了,请原谅,但我不认为广播接收器超时会导致这种特殊的崩溃。避免 10 秒的限制是一种很好的做法,但这与请求者遇到的问题不同。
    • 我的大脑只有 10 秒。 developer.android.com/training/articles/perf-anr.htmlIDK 是否也是导致崩溃的原因。
    • 你的观点很扎实,是一个很好的做法。但是,原始海报对一组特定设备有一个特定的问题。如果看到相同的症状(三星设备(尤其是 Galaxy S 4)等),我建议这篇文章的其他查看者检查 Christopher 的答案和 oba 的答案。
    • 我不是来抨击设备制造商的,否则会违反条款。
    【解决方案7】:

    始终正确的一件事是,此时设备会因一些内存而窒息(这通常是 GC 最有可能被触发的原因)。

    正如前面几乎所有作者所提到的,当 Android 尝试在应用处于后台时运行 GC 时,就会出现此问题。在我们观察到的大多数情况下,用户通过锁定屏幕来暂停应用程序。 这也可能表明应用程序中某处存在内存泄漏,或者设备已经加载过多。 因此,将其最小化的唯一合法方法是:

    • 确保没有内存泄漏,并且
    • 总体上减少应用程序的内存占用。

    【讨论】:

      【解决方案8】:
      try {
          Class<?> c = Class.forName("java.lang.Daemons");
          Field maxField = c.getDeclaredField("MAX_FINALIZE_NANOS");
          maxField.setAccessible(true);
          maxField.set(null, Long.MAX_VALUE);
      } catch (ClassNotFoundException e) {
          e.printStackTrace();
      } catch (NoSuchFieldException e) {
          e.printStackTrace();
      } catch (IllegalAccessException e) {
          e.printStackTrace();
      }
      

      【讨论】:

      • 如果睡眠持续时间 > 100 秒,这将无法解决问题。为什么不将其设置为 MAX_INT?
      • 对,我只是举个例子~
      • 这不应该工作,因为不断内联。更改字段值不会影响内联给调用者的值。
      【解决方案9】:

      finalizeQueue 可能太长了

      我认为 java 可能需要 GC.SuppressFinalize()GC.ReRegisterForFinalize() 让用户显式减少 finalizedQueue 长度

      如果有JVM的源代码,可以自己实现这些方法,比如android ROM maker

      【讨论】:

        【解决方案10】:

        这似乎是一个 Android 运行时错误。似乎有一个终结器在其单独的线程中运行,如果对象不在堆栈跟踪的当前帧中,则对对象调用 finalize() 方法。 例如以下代码(为验证此问题而创建)以崩溃结束。

        让我们有一些游标在 finalize 方法中做一些事情(例如 SqlCipher 的,做 close() 锁定到当前正在使用的数据库)

        private static class MyCur extends MatrixCursor {
        
        
            public MyCur(String[] columnNames) {
                super(columnNames);
            }
        
            @Override
            protected void finalize() {
                super.finalize();
        
                try {
                    for (int i = 0; i < 1000; i++)
                        Thread.sleep(30);
                } catch (InterruptedException e) {
                    e.printStackTrace();
                }
            }
        }
        

        我们在打开光标后做了一些长时间运行的事情:

        for (int i = 0; i < 7; i++) {
                new Thread(new Runnable() {
                    @Override
                    public void run() {
                        MyCur cur = null;
                        try {
                            cur = new MyCur(new String[]{});
                            longRun();
                        } finally {
                            cur.close();
                        }
                    }
        
                    private void longRun() {
                        try {
                            for (int i = 0; i < 1000; i++)
                                Thread.sleep(30);
                        } catch (InterruptedException e) {
                            e.printStackTrace();
                        }
                    }
                }).start();
            }
        

        这会导致以下错误:

        FATAL EXCEPTION: FinalizerWatchdogDaemon
                                                                                Process: la.la.land, PID: 29206
                                                                                java.util.concurrent.TimeoutException: MyCur.finalize() timed out after 10 seconds
                                                                                    at java.lang.Thread.sleep(Native Method)
                                                                                    at java.lang.Thread.sleep(Thread.java:371)
                                                                                    at java.lang.Thread.sleep(Thread.java:313)
                                                                                    at MyCur.finalize(MessageList.java:1791)
                                                                                    at java.lang.Daemons$FinalizerDaemon.doFinalize(Daemons.java:222)
                                                                                    at java.lang.Daemons$FinalizerDaemon.run(Daemons.java:209)
                                                                                    at java.lang.Thread.run(Thread.java:762)
        

        与 SqlCipher 的生产变体非常相似:

        12-21 15:40:31.668: E/EH(32131): android.content.ContentResolver$CursorWrapperInner.finalize() timed out after 10 seconds
        12-21 15:40:31.668: E/EH(32131): java.util.concurrent.TimeoutException: android.content.ContentResolver$CursorWrapperInner.finalize() timed out after 10 seconds
        12-21 15:40:31.668: E/EH(32131): 	at java.lang.Object.wait(Native Method)
        12-21 15:40:31.668: E/EH(32131): 	at java.lang.Thread.parkFor$(Thread.java:2128)
        12-21 15:40:31.668: E/EH(32131): 	at sun.misc.Unsafe.park(Unsafe.java:325)
        12-21 15:40:31.668: E/EH(32131): 	at java.util.concurrent.locks.LockSupport.park(LockSupport.java:161)
        12-21 15:40:31.668: E/EH(32131): 	at java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:840)
        12-21 15:40:31.668: E/EH(32131): 	at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireQueued(AbstractQueuedSynchronizer.java:873)
        12-21 15:40:31.668: E/EH(32131): 	at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(AbstractQueuedSynchronizer.java:1197)
        12-21 15:40:31.668: E/EH(32131): 	at java.util.concurrent.locks.ReentrantLock$FairSync.lock(ReentrantLock.java:200)
        12-21 15:40:31.668: E/EH(32131): 	at java.util.concurrent.locks.ReentrantLock.lock(ReentrantLock.java:262)
        12-21 15:40:31.668: E/EH(32131): 	at net.sqlcipher.database.SQLiteDatabase.lock(SourceFile:518)
        12-21 15:40:31.668: E/EH(32131): 	at net.sqlcipher.database.SQLiteProgram.close(SourceFile:294)
        12-21 15:40:31.668: E/EH(32131): 	at net.sqlcipher.database.SQLiteQuery.close(SourceFile:136)
        12-21 15:40:31.668: E/EH(32131): 	at net.sqlcipher.database.SQLiteCursor.close(SourceFile:510)
        12-21 15:40:31.668: E/EH(32131): 	at android.database.CursorWrapper.close(CursorWrapper.java:50)
        12-21 15:40:31.668: E/EH(32131): 	at android.database.CursorWrapper.close(CursorWrapper.java:50)
        12-21 15:40:31.668: E/EH(32131): 	at android.content.ContentResolver$CursorWrapperInner.close(ContentResolver.java:2746)
        12-21 15:40:31.668: E/EH(32131): 	at android.content.ContentResolver$CursorWrapperInner.finalize(ContentResolver.java:2757)
        12-21 15:40:31.668: E/EH(32131): 	at java.lang.Daemons$FinalizerDaemon.doFinalize(Daemons.java:222)
        12-21 15:40:31.668: E/EH(32131): 	at java.lang.Daemons$FinalizerDaemon.run(Daemons.java:209)
        12-21 15:40:31.668: E/EH(32131): 	at java.lang.Thread.run(Thread.java:762)

        恢复:尽快关闭光标。 至少在三星 S8 和 Android 7 上已发现问题。

        【讨论】:

          【解决方案11】:

          对于您创建的类(即不是 Android 的一部分),可以完全避免崩溃。

          任何实现finalize() 的类都有一些不可避免的崩溃概率,正如@oba 所解释的那样。所以不要使用终结器来执行清理,而是使用PhantomReferenceQueue

          例如,查看 React Native 中的实现:https://github.com/facebook/react-native/blob/master/ReactAndroid/src/main/java/com/facebook/jni/DestructorThread.java

          【讨论】:

            猜你喜欢
            • 1970-01-01
            • 2017-10-19
            • 1970-01-01
            • 1970-01-01
            • 1970-01-01
            • 1970-01-01
            • 1970-01-01
            • 1970-01-01
            相关资源
            最近更新 更多