如何处理:java.util.concurrent.TimeoutException:android.os.BinderProxy.finalize()10秒后超时错误?

我们在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) 

到目前为止,我们还没有在内部重现问题或找出可能造成的问题。

任何想法可以导致这一点? 任何想法如何debugging,并找出哪个部分的应用程序导致这一点? 任何事情都可以帮助解决问题。

更多Stacktraces:

 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 

充分披露 – 我是TLV DroidCon中前面提到的谈话的作者。

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

我仔细看了一下Android垃圾收集器代码的默认实现,以更好地理解为什么这个exception是抛出,以及可能的原因是什么。 我甚至在实验中发现了一个可能的根源。

问题的根源在于一个设备“进入hibernate”一段时间 – 这意味着操作系统决定通过停止大部分用户login进程一段时间来降低电池消耗,并closures屏幕,减lessCPU周期等等。这样做的方式是在一个Linux系统级别的进程被暂停中途运行。 这可能会在正常的应用程序执行期间的任何时候发生,但是它将在Native系统调用中停止,因为上下文切换是在内核级别上完成的。 所以 – 这就是Dalvik GCjoin故事的地方。 Dalvik GC代码(在AOSP站点的Dalvik项目中实现)不是一个复杂的代码片段。 它的基本工作方式在我的DroidCon幻灯片中进行了介绍。 我没有介绍的是基本的GC循环 – 在收集器有一个对象列表完成(和销毁)的点。 基地的循环逻辑可以这样简化:

  1. 采取starting_timestamp,
  2. 删除对象列表的对象释放,
  3. 释放对象 – 如果需要, finalize()并调用native destroy()
  4. 采取end_timestamp
  5. 计算( end_timestamp - starting_timestamp )并与硬编码超时值10秒进行比较,
  6. 如果超时已经达到 – 抛出concurrent.TimeoutException并终止进程。

现在考虑以下情况:

应用程序正在运行。 这不是面向用户的应用程序,它在后台运行。 在此后台操作期间,创build,使用对象并需要收集以释放内存。 应用程序不会打扰Wakelock – 因为这会影响电池不利,似乎没有必要。 这意味着应用程序将不时调用GC。 通常情况下,GC运行顺利完成。 系统有时(很less)会决定在GC运行中睡眠。 如果你运行你的应用程序足够长时间,就会发生这种情况,并密切监视Dalvik内存日志。 现在考虑基本的GC循环的时间戳逻辑 – 设备可以开始运行,取start_stamp,然后在系统对象的destroy()本机调用中hibernate。 当它醒来并恢复运行时, destroy()将结束,下一个end_stamp将是destroy()调用+hibernate时间的时间。 如果睡眠时间很长 – 超过10秒,则会引发并发超时exception。

我已经从分析python脚本生成的图表中看到了这一点 – 对于Android系统应用程序,不仅仅是我自己的受监视的应用程序。 收集足够的日志,你最终会看到它。

底线:

这个问题无法避免 – 如果你的应用在后台运行,你会遇到它。 你可以通过唤醒来缓解这个问题,防止设备进入睡眠状态,但这完全是一个不同的故事,一个令人头痛的问题,或者是另一个问题。

您可以通过减lessGC呼叫来最大限度地减less问题 – 使情况变得不太可能。 提示在幻灯片中。

我还没有机会翻过Dalvik 2(又名ART)GC代码 – 它拥有新一代的压缩function,或者在Android棒棒糖上进行了任何实验。

新增7/5/2015:

在查看崩溃types的崩溃报告聚合之后,看起来Android 5.0版本(带有ART的棒棒糖)的这些崩溃仅占崩溃types的0.5%。 这意味着ART GC变化减less了这些崩溃的频率。

已于6/1/2016添加:

看起来Android项目增加了很多关于GC如何在Dalvik 2.0(又名ART)中工作的信息。 你可以在这里阅读 – debuggingART垃圾收集 。 它还讨论了一些工具来获取有关您的应用程序的GC行为的信息。 将SIGQUIT发送到您的应用程序进程本质上会导致ANR,并将应用程序状态转储到日志文件进行分析。

我们不断地看到这一点,遍布我们的应用程序,使用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秒后超时

发生这种情况的设备绝大多数(但不是唯一的)由三星制造的设备。 这可能意味着我们的大部分用户正在使用三星设备; 或者它可能表示三星设备的问题。 我不太确定。

我想这不能真正回答你的问题,但我只是想强调这似乎很常见,而不是针对你的应用程序。

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

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中find了一条提示: https : //code.google.com/p/android/issues/detail?id= 53418# c3

广播接收器在10秒后超时。 可能你从广播接收机做asynchronous呼叫(错误),4.3实际上检测到它。

有一件事情总是正确的,就是在这个时候,这个设备会让某些内存窒息(这通常是GC最有可能被触发的原因)。

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

  • 确保没有内存泄漏,并且
  • 以减less一般应用程序的内存占用。

敲定队列可能太长了

我认为,Java可能需要GC.SuppressFinalize() & GC.ReRegisterForFinalize()让用户明确地减lessfinalizedQueue长度

如果JVM的源代码可用,可以自己实现这些方法,比如android ROM制造商

 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(); }