手机烧录完成后,开机向导发生了ANR的问题
然后发现,问题发生的时候存储颗粒性能急剧下降,IO降速严重
请问发生ANR的原因是什么?为何会导致存储颗粒性能急剧下降?
events <
timestamp_ms: 1672675286968
anr <
pid: 1906
process: "com.google.android.setupwizard"
process_class: 2
subject: "Input dispatching timed out (25d8646 com.google.android.setupwizard/com.google.android.setupwizard.carrier.SimMissingActivity (server) is not responding. Waited 13006ms for MotionEvent(deviceId=4, eve[...]"
uid: 10138
timestamp_ms: 1672675305664
window_ms: 300000
----- pid 1809 at 2023-01-03 00:01:45.711976309+0800 -----
Cmd line: com.google.android.gms.persistent
Build fingerprint: 'Aspera/AS8/AS8:13/TP1A.220624.014/1682565520:userdebug/release-keys'
ABI: 'arm'
Build type: optimized
Zygote loaded classes=21572 post zygote classes=6530
Dumping registered class loaders
#0 dalvik.system.PathClassLoader: [], parent #1
#1 java.lang.BootClassLoader: [], no parent
#2 dalvik.system.PathClassLoader: [/product/priv-app/GmsCoreGo/GmsCoreGo.apk!classes9.dex:/product/priv-app/GmsCoreGo/GmsCoreGo.apk!classes2.dex:/product/priv-app/GmsCoreGo/GmsCoreGo.apk!classes8.dex:/product/priv-app/GmsCoreGo/GmsCoreGo.apk!classes6.dex:/product/priv-app/GmsCoreGo/GmsCoreGo.apk!classes5.dex:/product/priv-app/GmsCoreGo/GmsCoreGo.apk:/product/priv-app/GmsCoreGo/GmsCoreGo.apk!classes4.dex:/product/priv-app/GmsCoreGo/GmsCoreGo.apk!classes7.dex:/product/priv-app/GmsCoreGo/GmsCoreGo.apk!classes3.dex], parent #1
#3 dalvik.system.PathClassLoader: [/system/framework/com.android.location.provider.jar], parent #1
#4 dalvik.system.PathClassLoader: [/system/framework/org.apache.http.legacy.jar], parent #1
Done dumping class loaders
Classes initialized: 0 in 0
Intern table: 42875 strong; 1302 weak
JNI: CheckJNI is off; globals=772 (plus 115 weak)
Libraries: /product/priv-app/GmsCoreGo/GmsCoreGo.apk!/lib/armeabi-v7a/libconscrypt_gmscore_jni.so /product/priv-app/GmsCoreGo/GmsCoreGo.apk!/lib/armeabi-v7a/libleveldbjni.so libandroid.so libaudioeffect_jni.so libcompiler_rt.so libframework-connectivity-jni.so libframework-connectivity-tiramisu-jni.so libicu_jni.so libjavacore.so libjavacrypto.so libjnigraphics.so libmedia_jni.so libopenjdk.so librs_jni.so librtp_jni.so libsoundpool.so libstats_jni.so libwebviewchromium_loader.so (18)
Heap: 15% free, 11MB/13MB; 298393 objects
Dumping cumulative Gc timings
Start Dumping Averages for 3 iterations for concurrent copying
SweepSystemWeaks: Sum: 10.810s Avg: 3.603s
CopyingPhase: Sum: 3.483s Avg: 1.161s
CaptureThreadRootsForMarking: Sum: 1.998s Avg: 666.288ms
MarkingPhase: Sum: 1.143s Avg: 381.053ms
Process mark stacks and References: Sum: 921.940ms Avg: 307.313ms
ScanImmuneSpaces: Sum: 105.618ms Avg: 35.206ms
VisitConcurrentRoots: Sum: 75.805ms Avg: 25.268ms
ScanCardsForSpace: Sum: 53.673ms Avg: 17.891ms
GrayAllDirtyImmuneObjects: Sum: 44.848ms Avg: 14.949ms
ClearFromSpace: Sum: 23.738ms Avg: 7.912ms
EnqueueFinalizerReferences: Sum: 22.715ms Avg: 7.571ms
ThreadListFlip: Sum: 15.525ms Avg: 5.175ms
FlipOtherThreads: Sum: 2.885ms Avg: 961.666us
ProcessReferences: Sum: 2.472ms Avg: 824us
FlipThreadRoots: Sum: 2.235ms Avg: 745us
InitializePhase: Sum: 1.992ms Avg: 664us
SweepLargeObjects: Sum: 1.839ms Avg: 613us
ForwardSoftReferences: Sum: 1.079ms Avg: 359.666us
MarkZygoteLargeObjects: Sum: 1.064ms Avg: 354.666us
EmptyRBMarkBitStack: Sum: 957us Avg: 319us
VisitNonThreadRoots: Sum: 798us Avg: 266us
MarkStackAsLive: Sum: 355us Avg: 118.333us
(Paused)GrayAllNewlyDirtyImmuneObjects: Sum: 272us Avg: 90.666us
SwapBitmaps: Sum: 218us Avg: 72.666us
ResumeRunnableThreads: Sum: 215us Avg: 71.666us
RecordFree: Sum: 190us Avg: 63.333us
SweepAllocSpace: Sum: 155us Avg: 51.666us
(Paused)ClearCards: Sum: 144us Avg: 48us
ReclaimPhase: Sum: 88us Avg: 29.333us
ResumeOtherThreads: Sum: 61us Avg: 20.333us
Sweep: Sum: 45us Avg: 15us
(Paused)FlipCallback: Sum: 31us Avg: 10.333us
(Paused)SetFromSpace: Sum: 20us Avg: 6.666us
UnBindBitmaps: Sum: 16us Avg: 5.333us
Done Dumping Averages
concurrent copying paused: Sum: 16.642ms 99% C.I. 0.109ms-15.050ms Avg: 2.773ms Max: 15.362ms
concurrent copying freed-bytes: Avg: 7787KB Max: 11MB Min: 2190KB
Freed-bytes histogram: 1280:1,8960:1,11520:1
concurrent copying total time: 18.717s mean time: 6.239s
concurrent copying freed: 371930 objects with total size 22MB
concurrent copying throughput: 19871.2/s / 1248KB/s per cpu-time: 59957353/s / 57MB/s
concurrent copying tracing throughput: 345KB/s per cpu-time: 15MB/s
Average major GC reclaim bytes ratio 1.05328 over 3 GC cycles
Average major GC copied live bytes ratio 0.548672 over 8 major GCs
Cumulative bytes moved 36762928
Cumulative objects moved 687967
Peak regions allocated 92 (23MB) / 512 (128MB)
Total madvise time 42.542ms
Start Dumping Averages for 5 iterations for young concurrent copying
Process mark stacks and References: Sum: 1.162s Avg: 232.478ms
ScanCardsForSpace: Sum: 483.782ms Avg: 96.756ms
ScanImmuneSpaces: Sum: 353.504ms Avg: 70.700ms
CopyingPhase: Sum: 179.882ms Avg: 35.976ms
VisitConcurrentRoots: Sum: 160.566ms Avg: 32.113ms
ForwardSoftReferences: Sum: 146.410ms Avg: 29.282ms
ClearFromSpace: Sum: 65.145ms Avg: 13.029ms
SweepArray: Sum: 61.804ms Avg: 12.360ms
EnqueueFinalizerReferences: Sum: 56.763ms Avg: 11.352ms
ThreadListFlip: Sum: 53.692ms Avg: 10.738ms
SweepSystemWeaks: Sum: 49.940ms Avg: 9.988ms
FlipThreadRoots: Sum: 40.286ms Avg: 8.057ms
GrayAllDirtyImmuneObjects: Sum: 26.127ms Avg: 5.225ms
ReclaimPhase: Sum: 21.117ms Avg: 4.223ms
FlipOtherThreads: Sum: 11.259ms Avg: 2.251ms
EmptyRBMarkBitStack: Sum: 11.003ms Avg: 2.200ms
InitializePhase: Sum: 8.098ms Avg: 1.619ms
ProcessReferences: Sum: 7.095ms Avg: 1.419ms
ResumeOtherThreads: Sum: 1.906ms Avg: 381.200us
FreeList: Sum: 1.653ms Avg: 330.600us
MarkZygoteLargeObjects: Sum: 984us Avg: 196.800us
VisitNonThreadRoots: Sum: 895us Avg: 179us
(Paused)ClearCards: Sum: 778us Avg: 155.600us
ResumeRunnableThreads: Sum: 496us Avg: 99.200us
RecordFree: Sum: 339us Avg: 67.800us
(Paused)GrayAllNewlyDirtyImmuneObjects: Sum: 308us Avg: 61.600us
SwapBitmaps: Sum: 123us Avg: 24.600us
ResetStack: Sum: 106us Avg: 21.200us
UnBindBitmaps: Sum: 67us Avg: 13.400us
(Paused)SetFromSpace: Sum: 32us Avg: 6.400us
(Paused)FlipCallback: Sum: 25us Avg: 5us
Done Dumping Averages
young concurrent copying paused: Sum: 131.468ms 99% C.I. 0.288ms-58.700ms Avg: 13.146ms Max: 58.859ms
young concurrent copying freed-bytes: Avg: 4277KB Max: 5935KB Min: 2216KB
Freed-bytes histogram: 1920:1,3200:1,3840:1,4480:1,5760:1
young concurrent copying total time: 2.906s mean time: 581.315ms
young concurrent copying freed: 323720 objects with total size 20MB
young concurrent copying throughput: 111397/s / 7360KB/s per cpu-time: 59194767/s / 56MB/s
young concurrent copying tracing throughput: 2720KB/s per cpu-time: 20MB/s
Average minor GC reclaim bytes ratio 0.351545 over 5 GC cycles
Average minor GC copied live bytes ratio 0.275329 over 6 minor GCs
Cumulative bytes moved 6780736
Cumulative objects moved 131337
Peak regions allocated 92 (23MB) / 512 (128MB)
Total time spent in GC: 21.623s
Mean GC size throughput: 2069KB/s per cpu-time: 56MB/s
Mean GC object throughput: 32170.6 objects/s
Total number of allocations 994043
Total bytes allocated 54MB
Total bytes freed 43MB
Free memory 2071KB
Free memory until GC 2071KB
Free memory until OOME 116MB
Total memory 13MB
Max memory 128MB
Zygote space size 7432KB
Total mutator paused time: 148.110ms
Total time waiting for GC to complete: 12.154us
Total GC count: 8
Total GC time: 21.623s
Total blocking GC count: 0
Total blocking GC time: 0
Total pre-OOME GC count: 0
Histogram of GC count per 10000 ms: 0:6,1:2,2:1,3:1
Histogram of blocking GC count per 10000 ms: 0:10
Native bytes total: 7899739 registered: 1298371
Total native bytes at last GC: 7208427
/system/framework/oat/arm/android.hidl.base-V1.0-java.odex: verify
/system/framework/oat/arm/android.hidl.manager-V1.0-java.odex: verify
/system/framework/oat/arm/android.test.base.odex: verify
/system/framework/oat/arm/org.apache.http.legacy.odex: speed-profile
/system/framework/oat/arm/com.android.media.remotedisplay.odex: verify
/system/framework/oat/arm/com.android.location.provider.odex: verify
/product/priv-app/GmsCoreGo/oat/arm/GmsCoreGo.odex: speed-profile
Current JIT code cache size (used / resident): 343KB / 348KB
Current JIT data cache size (used / resident): 195KB / 224KB
Zygote JIT code cache size (at point of fork): 20KB / 32KB
Zygote JIT data cache size (at point of fork): 14KB / 32KB
Current JIT mini-debug-info size: 30KB
Current JIT capacity: 1024KB
Current number of JIT JNI stub entries: 0
Current number of JIT code cache entries: 273
Total number of JIT baseline compilations: 284
Total number of JIT optimized compilations: 9
Total number of JIT compilations for on stack replacement: 1
Total number of JIT code cache collections: 6
Memory used for stack maps: Avg: 482B Max: 16KB Min: 12B
Memory used for compiled code: Avg: 1676B Max: 29KB Min: 12B
Memory used for profiling info: Avg: 298B Max: 5752B Min: 16B
Start Dumping Averages for 317 iterations for JIT timings
Code cache collection: Sum: 1.772s Avg: 5.592ms
Compiling baseline: Sum: 1.225s Avg: 3.864ms
Compiling OSR: Sum: 188.914ms Avg: 595.943us
Compiling optimized: Sum: 168.025ms Avg: 530.047us
TrimMaps: Sum: 35.674ms Avg: 112.536us
Done Dumping Averages
Memory used for compilation: Avg: 110KB Max: 2934KB Min: 10KB
ProfileSaver total_bytes_written=24903
ProfileSaver total_number_of_writes=2
ProfileSaver total_number_of_code_cache_queries=2
ProfileSaver total_number_of_skipped_writes=0
ProfileSaver total_number_of_failed_writes=0
ProfileSaver total_ms_of_sleep=81837
ProfileSaver total_ms_of_work=4285
ProfileSaver total_number_of_hot_spikes=6
ProfileSaver total_number_of_wake_ups=7
Number of JIT inline cache deoptimizations: 1
*** ART internal metrics ***
Metadata:
timestamp_since_start_ms: 101804
Metrics:
ClassLoadingTotalTime: count = 96390326
ClassVerificationTotalTime: count = 0
ClassVerificationCount: count = 0
WorldStopTimeDuringGCAvg: count = 18514
YoungGcCount: count = 5
FullGcCount: count = 3
TotalBytesAllocated: count = 55482464
TotalGcCollectionTime: count = 21795
YoungGcThroughputAvg: count = 5
FullGcThroughputAvg: count = 17
YoungGcTracingThroughputAvg: count = 2
FullGcTracingThroughputAvg: count = 4
JitMethodCompileTotalTime: count = 21418135
JitMethodCompileCount: count = 294
YoungGcCollectionTime: range = 0...60000, buckets: 5,0,0,0,0,0,0,0,0,0,0,0,0,0,0
FullGcCollectionTime: range = 0...60000, buckets: 2,0,0,0,1,0,0,0,0,0,0,0,0,0,0
YoungGcThroughput: range = 0...10000, buckets: 5,0,0,0,0,0,0,0,0,0,0,0,0,0,0
FullGcThroughput: range = 0...10000, buckets: 3,0,0,0,0,0,0,0,0,0,0,0,0,0,0
YoungGcTracingThroughput: range = 0...10000, buckets: 5,0,0,0,0,0,0,0,0,0,0,0,0,0,0
FullGcTracingThroughput: range = 0...10000, buckets: 3,0,0,0,0,0,0,0,0,0,0,0,0,0,0
GcWorldStopTime: count = 148113
GcWorldStopCount: count = 8
YoungGcScannedBytes: count = 8096392
YoungGcFreedBytes: count = 17687280
YoungGcDuration: count = 3003
FullGcScannedBytes: count = 6624120
FullGcFreedBytes: count = 21829928
FullGcDuration: count = 18792
*** Done dumping ART internal metrics ***
suspend all histogram: Sum: 169.857ms 99% C.I. 0.007ms-54.865ms Avg: 4.995ms Max: 58.583ms
DALVIK THREADS (58):
"Signal Catcher" daemon prio=10 tid=3 Runnable
| group="system" sCount=0 ucsCount=0 flags=0 obj=0x13c800b0 self=0xae552a00
| sysTid=1815 nice=-20 cgrp=foreground sched=0/0 handle=0x9d3a01c0
| state=R schedstat=( 300226844 17229960 116 ) utm=21 stm=8 core=5 HZ=100
| stack=0x9d2a5000-0x9d2a7000 stackSize=1004KB
| held mutexes= "mutator lock"(shared held)
native: #00 pc 004b4559 /apex/com.android.art/lib/libart.so (art::DumpNativeStack(std::__1::basic_ostream<char, std::__1::char_traits >&, int, BacktraceMap*, char const*, art::ArtMethod*, void*, bool)+68) (BuildId: d26242917853dc8fd5beaa9b9fdb2378)
native: #01 pc 00505205 /apex/com.android.art/lib/libart.so (art::Thread::DumpStack(std::__1::basic_ostream<char, std::__1::char_traits >&, bool, BacktraceMap*, bool) const+120) (BuildId: d26242917853dc8fd5beaa9b9fdb2378)
native: #02 pc 0033cf77 /apex/com.android.art/lib/libart.so (art::Thread::Dump(std::__1::basic_ostream<char, std::__1::char_traits >&, bool, BacktraceMap*, bool) const+34) (BuildId: d26242917853dc8fd5beaa9b9fdb2378)
native: #03 pc 0050c5c3 /apex/com.android.art/lib/libart.so (art::DumpCheckpoint::Run(art::Thread*)+170) (BuildId: d26242917853dc8fd5beaa9b9fdb2378)
native: #04 pc 00248e0f /apex/com.android.art/lib/libart.so (art::ThreadList::Dump(std::__1::basic_ostream<char, std::__1::char_traits >&, bool)+1134) (BuildId: d26242917853dc8fd5beaa9b9fdb2378)
native: #05 pc 0050b9b9 /apex/com.android.art/lib/libart.so (art::ThreadList::DumpForSigQuit(std::__1::basic_ostream<char, std::__1::char_traits >&)+224) (BuildId: d26242917853dc8fd5beaa9b9fdb2378)
native: #06 pc 004f0175 /apex/com.android.art/lib/libart.so (art::Runtime::DumpForSigQuit(std::__1::basic_ostream<char, std::__1::char_traits >&)+132) (BuildId: d26242917853dc8fd5beaa9b9fdb2378)
native: #07 pc 004f9877 /apex/com.android.art/lib/libart.so (art::SignalCatcher::HandleSigQuit()+302) (BuildId: d26242917853dc8fd5beaa9b9fdb2378)
native: #08 pc 004f906b /apex/com.android.art/lib/libart.so (art::SignalCatcher::Run(void*)+186) (BuildId: d26242917853dc8fd5beaa9b9fdb2378)
native: #09 pc 000ad343 /apex/com.android.runtime/lib/bionic/libc.so (__pthread_start(void*)+40) (BuildId: af6810c270871aca8335b7324814f55c)
native: #10 pc 000643fd /apex/com.android.runtime/lib/bionic/libc.so (__start_thread+30) (BuildId: af6810c270871aca8335b7324814f55c)
(no managed stack frames)
"main" prio=5 tid=1 Waiting
| group="main" sCount=1 ucsCount=0 flags=1 obj=0x71a75248 self=0xae550e00
| sysTid=1809 nice=0 cgrp=foreground sched=0/0 handle=0xae96c470
| state=S schedstat=( 5755068373 6344567166 9418 ) utm=394 stm=181 core=0 HZ=100
| stack=0xbe0f5000-0xbe0f7000 stackSize=8188KB
| held mutexes=
at jdk.internal.misc.Unsafe.park(Native method)
引用chatGPT作答,这个问题的原因可能是ANR(应用程序未响应),这意味着应用程序在执行某个操作时无法响应用户输入,超过了一定时间阈值。在这种情况下,Android系统会强制关闭应用程序。
ANR可以由许多原因引起,例如主线程被阻塞或死锁、CPU或内存使用过高等。在这种情况下,看起来ANR可能是由于开机向导执行某个操作时被阻塞而导致的。
存储颗粒性能急剧下降和IO降速严重的问题可能是由于ANR发生时存储系统无法正常工作,导致性能下降。这可能是由于ANR导致了一些IO操作未完成,导致存储系统无法正常读取或写入数据。如果ANR发生在开机向导等系统级别应用程序中,那么存储系统的问题可能会影响整个系统的性能。