如何从此 ANR 日志中获取有用的信息

How to get something useful from this ANR log

几周来我一直在与 ANR 作斗争,但我仍然对 this 这样的日志感到茫然。 Whosebug 太长了,我不知道哪一部分可能有用。 它通常发生在初始同步期间,当时后台正在处理大量网络请求(而且我几乎 100% 确定主线程中没有这些请求)而且我也做了很多 UI 诸如通过 RxJava 可观察对象从共享首选项填充 recyclerviews 之类的东西所以我观察到 SharedPreferences 的巨大变化并使用 sample 方法来处理可能的背压。感谢任何提示,我完全迷路了。

你在那里有多个进程的线程转储。要找到有用的部分,您可以搜索 "Cmd line" 直到找到您的进程("cz.vcelka.androidapp",pid 为 21574)。

如果您收到 ANR,这意味着您的主线程以某种方式被阻塞,那么您应该查看它的堆栈跟踪。在这里:

"main" prio=5 tid=1 Waiting
  | group="main" sCount=1 dsCount=0 obj=0x74bc2fa0 self=0xb4db6500
  | sysTid=21574 nice=0 cgrp=default sched=0/0 handle=0xb6fc1b34
  | state=S schedstat=( 0 0 0 ) utm=785 stm=88 core=1 HZ=100
  | stack=0xbe29a000-0xbe29c000 stackSize=8MB
  | held mutexes=
  at java.lang.Object.wait!(Native method)
  - waiting on <0x05853836> (a java.lang.Object)
  at java.lang.Thread.parkFor$(Thread.java:1220)
  - locked <0x05853836> (a java.lang.Object)
  at sun.misc.Unsafe.park(Unsafe.java:299)
  at java.util.concurrent.locks.LockSupport.park(LockSupport.java:158)
  at java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:810)
  at java.util.concurrent.locks.AbstractQueuedSynchronizer.doAcquireSharedInterruptibly(AbstractQueuedSynchronizer.java:971)
  at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireSharedInterruptibly(AbstractQueuedSynchronizer.java:1278)
  at java.util.concurrent.CountDownLatch.await(CountDownLatch.java:203)
  at android.app.SharedPreferencesImpl$EditorImpl.run(SharedPreferencesImpl.java:366)
  at android.app.QueuedWork.waitToFinish(QueuedWork.java:88)
  at android.app.ActivityThread.handleStopActivity(ActivityThread.java:3560)
  at android.app.ActivityThread.-wrap20(ActivityThread.java:-1)
  at android.app.ActivityThread$H.handleMessage(ActivityThread.java:1373)
  at android.os.Handler.dispatchMessage(Handler.java:102)
  at android.os.Looper.loop(Looper.java:148)
  at android.app.ActivityThread.main(ActivityThread.java:5417)
  at java.lang.reflect.Method.invoke!(Native method)
  at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:726)
  at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:616)

所以你的主线程被阻塞等待 CountDownLatch inside SharedPreferences 代码。我们可以查看 SharedPreferences 的源代码以了解更多信息。在某些时候,当您调用 SharedPreferences.Editor.apply(), the SharedPreferences code enqueued the write to disk to a worker thread. It also called QueuedWork.add(awaitCommit) 时,其中 awaitCommit 是等待写入操作(通过 CountDownLatch)的 Runnable,而 QueuedWork.add() 是当 activity 的 onPause 方法被调用时,将要在主线程 上完成的工作排队的方法 。这就是发生的事情:onPause 被调用,现在主线程卡在等待工作线程完成其写入操作。

现在的问题是您post编辑的日志不完整。缺少几个线程,包括从未调用 CountDownLatch.countDown() 的工作线程,因此无法判断是什么导致了死锁。如果您 post 整个日志(对于您的过程,我认为其他的不会有用),我们可能会提供更多帮助。

编辑:我注意到 运行 出现了同样的问题。对于他们来说,工作线程卡在 fsync(2)。如果文件很大和/或磁盘很忙,fsync 可能会非常慢(如多秒)。我想这可能是导致 ANR 的原因。我不确定这是否会被归类为 SharedPreferences 中的错误......即使从 onPause 调用,在主线程上触发可能的长时间阻塞操作似乎有点奇怪......如果这个确实是你的问题,我能想到的唯一解决方法是使用 commit() 而不是 apply(),因为那样会同步写入。您应该从后台线程执行此操作,因为在您的特定设置中似乎需要很长时间才能刷新到磁盘!

或者您的 SharedPreferences 文件太大了,在这种情况下您可以尝试将其精简(例如使用数据库)。