Wie bekomme ich etwas nützliches aus diesem ANR log

Question

Ich habe seit einigen Wochen mit ANRs zu kämpfen, aber ich fühle mich immer noch blind mit Logs wie this. Es ist zu lang für stackoverflow und ich habe keine Ahnung, welcher Teil nützlich sein könnte. Es passiert in der Regel während der ersten Synchronisierung, wenn eine Tonne Netzwerkanforderung im Hintergrund verarbeitet wird (und ich bin fast 100% sicher, dass das nicht im Hauptthread ist) und ich mache auch eine Menge UI-Sachen wie Recycler-Ansichten von gemeinsamen Präferenzen über RxJava-Observablen zu füllen, daher beobachte ich massive Änderungen in SharedPreferences und verwende die Methode sample, um möglichen Gegendruck zu bewältigen. Danke für irgendwelche Tipps, ich bin total verloren.

Answer 1

Sie haben Thread Dumps für mehrere Prozesse in dort. Um zum nützlichen Teil zu gelangen, können Sie nach "Cmd line" suchen, bis Sie Ihren Prozess gefunden haben ("cz.vcelka.androidapp", die PID war 21574).

Wenn Sie eine ANR erhalten, die bedeutet, dass Ihr Haupt-Thread irgendwie blockiert ist, sollten Sie sich die Stack-Verfolgung ansehen. Hier ist sie:

"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$1.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) 

Also Ihr Haupt-Thread ist auf einem CountDownLatch innerhalb SharedPreferences Code gesperrt warten. Wir können uns den Quellcode von SharedPreferences ansehen, um mehr zu erfahren. An einem bestimmten Punkt, als Sie SharedPreferences.Editor.apply() anriefen, stellte der Code SharedPreferences den Write to Disk in einen Worker-Thread ein. Es auch genannt QueuedWork.add(awaitCommit), wo ein awaitCommitRunnable ist, die (mittels CountDownLatch) auf der Schreiboperation wartet, und QueuedWork.add() ist eine Methode, die Arbeit auf Warteschlange einreiht auf dem Haupt-Thread, wenn die Verfahren der Aktivität durchgeführt werden aufgerufen. Das ist, was passiert ist: wurde aufgerufen, und jetzt ist der Haupt-Thread auf den Worker-Thread warten, um seinen Schreibvorgang abzuschließen.

Jetzt ist das Problem, dass das Protokoll, das Sie gebucht haben, unvollständig ist. Es fehlen mehrere Threads, einschließlich des Worker-Threads, der nie CountDownLatch.countDown() aufgerufen hat. Daher ist es nicht möglich festzustellen, was den Deadlock verursacht. Wenn Sie das ganze Protokoll veröffentlichen (für Ihren Prozess, glaube ich nicht, dass die anderen nützlich sein werden), können wir wahrscheinlich mehr helfen.

Edit: Ich bemerkte, dass someone else here in das gleiche Problem lief. Für sie war der Arbeiterfaden in fsync(2) stecken geblieben. fsync kann sehr langsam sein (wie in mehreren Sekunden), wenn die Datei groß ist und/oder die Festplatte beschäftigt ist. Ich nehme an, das könnte die ANR verursachen. Ich bin nicht sicher, ob das als Bug in SharedPreferences klassifizieren würde ... Scheint ein bisschen komisch, möglicherweise lange blockierende Operationen auf dem Hauptthread auszulösen, selbst wenn von aufgerufen ... Wenn das in der Tat Ihr Problem ist, die einzige Problemumgehung Ich kann mir vorstellen, commit() statt apply() zu verwenden, da das den Schreibvorgang synchron erledigt. Sie sollten es aus einem Hintergrundthread tun, da es in Ihrem speziellen Setup scheint, dass es ziemlich lange dauern kann, um auf die Festplatte zu spülen!

Oder vielleicht Ihre SharedPreferences Datei ist einfach viel zu groß, in diesem Fall könnten Sie versuchen, es schlank (z. B. mit einer Datenbank).