ANR 分析
am_anr 信息
11-01 09:47:23.134 1000 1702 11961 I am_anr : [0,8139,com.tencent.mobileqq:peak,952647236,Input dispatching timed out (d52f15b com.tencent.mobileqq/com.tencent.aelight.camera.aebase.QIMCameraCaptureActivity (server) is not responding. Waited 5001ms for MotionEvent(deviceId=5, eventTime=715537129640000, source=0x00001002, displayId=0, action=DOWN, actionButton=0x00000000, flags=0x00100000, metaState=0x00000000, buttonState=0x00000000, classification=NONE, edgeFlags=0x00000000, xPrecision=1.0, yPrecision=1.0, xCursorPosition=nan, yCursorPosition=nan, pointers=[0: (549.0, 1258.0)]), policyFlags=0x62000000)]
可以看见:
发生anr的时间点:11-01 09:47:23.134
进程pid:8139
进程名:com.tencent.mobileqq:peak
发生ANR的类型是:Input dispatching timed out
发生的具体类或者原因:com.tencent.mobileqq/com.tencent.aelight.camera.aebase.QIMCameraCaptureActivity (server) is not responding. Waited 5001ms for MotionEvent
ANR in 信息
-
分析CPU的负载,CPU的统计时间段,使用率等信息
11-01 09:47:44.047 1000 1702 11961 E ActivityManager: ANR in com.tencent.mobileqq:peak (com.tencent.mobileqq/com.tencent.aelight.camera.aebase.QIMCameraCaptureActivity) (进程名)
11-01 09:47:44.047 1000 1702 11961 E ActivityManager: PID: 8139 (进程pid)
11-01 09:47:44.047 1000 1702 11961 E ActivityManager: Reason: Input dispatching timed out (d52f15b com.tencent.mobileqq/com.tencent.aelight.camera.aebase.QIMCameraCaptureActivity (server) is not responding. Waited 5001ms for MotionEvent(deviceId=5, eventTime=715537129640000, source=0x00001002, displayId=0, action=DOWN, actionButton=0x00000000, flags=0x00100000, metaState=0x00000000, buttonState=0x00000000, classification=NONE, edgeFlags=0x00000000, xPrecision=1.0, yPrecision=1.0, xCursorPosition=nan, yCursorPosition=nan, pointers=[0: (549.0, 1258.0)]), policyFlags=0x62000000) (ANR原因)
11-01 09:47:44.047 1000 1702 11961 E ActivityManager: Parent: com.tencent.mobileqq/com.tencent.aelight.camera.aebase.QIMCameraCaptureActivity
11-01 09:47:44.047 1000 1702 11961 E ActivityManager: ErrorId: f63a09ce-81cd-4c5f-88ed-1f2cb99a2e85
11-01 09:47:44.047 1000 1702 11961 E ActivityManager: Frozen: false
11-01 09:47:44.047 1000 1702 11961 E ActivityManager: Load: 0.03 / 0.05 / 0.09
(Load表明是1分钟,5分钟,15分钟CPU的负载)
11-01 09:47:44.047 1000 1702 11961 E ActivityManager: ----- Output from /proc/pressure/memory -----
11-01 09:47:44.047 1000 1702 11961 E ActivityManager: some avg10=0.04 avg60=0.08 avg300=0.06 total=3337807361
11-01 09:47:44.047 1000 1702 11961 E ActivityManager: full avg10=0.02 avg60=0.03 avg300=0.00 total=469319805
(CPU内存压力)
11-01 09:47:44.047 1000 1702 11961 E ActivityManager: ----- End output from /proc/pressure/memory -----
11-01 09:47:44.047 1000 1702 11961 E ActivityManager:
11-01 09:47:44.047 1000 1702 11961 E ActivityManager: CPU usage from 0ms to 20926ms later (2021-11-01 09:47:23.048 to 2021-11-01 09:47:43.973):
(ANR发生时间段CPU的使用率)
11-01 09:47:44.047 1000 1702 11961 E ActivityManager: 13%(CPU的使用率) 1702(进程号)/system_server(进程名): 7.6% (用户态的使用率)user + 5.4% (内核态的使用率) kernel / faults: 14349 (高速缓存的缺页次数) minor 521 major(内存的缺页次数)
。。。
11-01 09:47:44.047 1000 1702 11961 E ActivityManager: 3.7% 8139/com.tencent.mobileqq:peak: 2.1% user + 1.5% kernel / faults: 1118 minor
。。。
11-01 09:47:44.048 1000 1702 11961 E ActivityManager: 9.2% TOTAL: 4.2% user + 3.6% kernel + 0.2% iowait + 0.9% irq + 0.1% softirq
Trace信息解读
Java进程trace信息解读
//进程pid :11881 dump trace时间:2022-04-22 21:09:11
----- pid 11881 at 2022-04-22 21:09:11.860285165+0800 -----
//进程名字:com.baidu.netdisk
Cmd line: com.baidu.netdisk
//ROM 编译版本信息
Build fingerprint: 'Xiaomi/mona/mona:12/SKQ1.220213.001/22.4.22:user/release-keys'
//进程abi
ABI: 'arm64'
Build type: optimized
Zygote loaded classes=19784 post zygote classes=8000
Dumping registered class loaders
#0 dalvik.system.PathClassLoader: [], parent #1
#1 java.lang.BootClassLoader: [], no parent
#2 dalvik.system.PathClassLoader: [/data/app/~~B16CRjC1QDRuqT0GB9RRGA==/com.baidu.netdisk-yCTMDER970GzYnBro9H_dg==/base.apk:/data/app/~~B16CRjC1QDRuqT0GB9RRGA==/com.baidu.netdisk-yCTMDER970GzYnBro9H_dg==/base.apk!classes48.dex:/data/app/~~B16CRjC1QDRuqT0GB9RRGA==/com.baidu.netdisk-yCTMDER970GzYnBro9H_dg==/base.apk!classes45.dex:/data/app/~~B16CRjC1QDRuqT0GB9RRGA==/com.baidu.netdisk-yCTMDER970GzYnBro9H_dg==/base.apk!classes14.dex:/data/app/~~B16CRjC1QDRuqT0GB9RRGA==/com.baidu.netdisk-yCTMDER970GzYnBro9H_dg==/base.apk!classes24.dex:/data/app/~~B16CRjC1QDRuqT0GB9RRGA==/com.baidu.netdisk-yCTMDER970GzYnBro9H_dg==/base.apk!classes9.dex:/data/app/~~B16CRjC1QDRuqT0GB9RRGA==/com.baidu.netdisk-yCTMDER970GzYnBro9H_dg==/base.apk!classes8.dex:/data/app/~~B16CRjC1QDRuqT0GB9RRGA==/com.baidu.netdisk-yCTMDER970GzYnBro9H_dg==/base.apk!classes37.dex:/data/app/~~B16CRjC1QDRuqT0GB9RRGA==/com.baidu.netdisk-yCTMDER970GzYnBro9H_dg==/base.apk!classes4.dex:/data/app/~~B16CRjC1QDRuqT0GB9RRGA==/com.baidu.netdisk-yCTMDER970GzYnBro9H_dg==/base.apk!classes49.dex:/data/app/~~B16CRjC1QDRuqT0GB9RRGA==/com.baidu.netdisk-yCTMDER970GzYnBro9H_dg==/base.apk!classes31.dex:/data/app/~~B16CRjC1QDRuqT0GB9RRGA==/com.baidu.netdisk-yCTMDER970GzYnBro9H_dg==/base.apk!classes10.dex:/data/app/~~B16CRjC1QDRuqT0GB9RRGA==/com.baidu.netdisk-yCTMDER970GzYnBro9H_dg==/base.apk!classes23.dex:/data/app/~~B16CRjC1QDRuqT0GB9RRGA==/com.baidu.netdisk-yCTMDER970GzYnBro9H_dg==/base.apk!classes13.dex:/data/app/~~B16CRjC1QDRuqT0GB9RRGA==/com.baidu.netdisk-yCTMDER970GzYnBro9H_dg==/base.apk!classes34.dex:/data/app/~~B16CRjC1QDRuqT0GB9RRGA==/com.baidu.netdisk-yCTMDER970GzYnBro9H_dg==/base.apk!classes5.dex:/data/app/~~B16CRjC1QDRuqT0GB9RRGA==/com.baidu.netdisk-yCTMDER970GzYnBro9H_dg==/base.apk!classes21.dex:/data/app/~~B16CRjC1QDRuqT0GB9RRGA==/com.baidu.netdisk-yCTMDER970GzYnBro9H_dg==/base.apk!classes26.dex:/data/app/~~B16CRjC1QDRuqT0GB9RRGA==/com.baidu.netdisk-yCTMDER970GzYnBro9H_dg==/base.apk!classes6.dex:/data/app/~~B16CRjC1QDRuqT0GB9RRGA==/com.baidu.netdisk-yCTMDER970GzYnBro9H_dg==/base.apk!classes44.dex:/data/app/~~B16CRjC1QDRuqT0GB9RRGA==/com.baidu.netdisk-yCTMDER970GzYnBro9H_dg==/base.apk!classes7.dex:/data/app/~~B16CRjC1QDRuqT0GB9RRGA==/com.baidu.netdisk-yCTMDER970GzYnBro9H_dg==/base.apk!classes36.dex:/data/app/~~B16CRjC1QDRuqT0GB9RRGA==/com.baidu.netdisk-yCTMDER970GzYnBro9H_dg==/base.apk!classes32.dex:/data/app/~~B16CRjC1QDRuqT0GB9RRGA==/com.baidu.netdisk-yCTMDER970GzYnBro9H_dg==/base.apk!classes35.dex:/data/app/~~B16CRjC1QDRuqT0GB9RRGA==/com.baidu.netdisk-yCTMDER970GzYnBro9H_dg==/base.apk!classes12.dex:/data/app/~~B16CRjC1QDRuqT0GB9RRGA==/com.baidu.netdisk-yCTMDER970GzYnBro9H_dg==/base.apk!classes33.dex:/data/app/~~B16CRjC1QDRuqT0GB9RRGA==/com.baidu.netdisk-yCTMDER970GzYnBro9H_dg==/base.apk!classes28.dex:/data/app/~~B16CRjC1QDRuqT0GB9RRGA==/com.baidu.netdisk-yCTMDER970GzYnBro9H_dg==/base.apk!classes43.dex:/data/app/~~B16CRjC1QDRuqT0GB9RRGA==/com.baidu.netdisk-yCTMDER970GzYnBro9H_dg==/base.apk!classes18.dex:/data/app/~~B16CRjC1QDRuqT0GB9RRGA==/com.baidu.netdisk-yCTMDER970GzYnBro9H_dg==/base.apk!classes3.dex:/data/app/~~B16CRjC1QDRuqT0GB9RRGA==/com.baidu.netdisk-yCTMDER970GzYnBro9H_dg==/base.apk!classes29.dex:/data/app/~~B16CRjC1QDRuqT0GB9RRGA==/com.baidu.netdisk-yCTMDER970GzYnBro9H_dg==/base.apk!classes15.dex:/data/app/~~B16CRjC1QDRuqT0GB9RRGA==/com.baidu.netdisk-yCTMDER970GzYnBro9H_dg==/base.apk!classes20.dex:/data/app/~~B16CRjC1QDRuqT0GB9RRGA==/com.baidu.netdisk-yCTMDER970GzYnBro9H_dg==/base.apk!classes25.dex:/data/app/~~B16CRjC1QDRuqT0GB9RRGA==/com.baidu.netdisk-yCTMDER970GzYnBro9H_dg==/base.apk!classes2.dex:/data/app/~~B16CRjC1QDRuqT0GB9RRGA==/com.baidu.netdisk-yCTMDER970GzYnBro9H_dg==/base.apk!classes11.dex:/data/app/~~B16CRjC1QDRuqT0GB9RRGA==/com.baidu.netdisk-yCTMDER970GzYnBro9H_dg==/base.apk!classes19.dex:/data/app/~~B16CRjC1QDRuqT0GB9RRGA==/com.baidu.netdisk-yCTMDER970GzYnBro9H_dg==/base.apk!classes51.dex:/data/app/~~B16CRjC1QDRuqT0GB9RRGA==/com.baidu.netdisk-yCTMDER970GzYnBro9H_dg==/base.apk!classes42.dex:/data/app/~~B16CRjC1QDRuqT0GB9RRGA==/com.baidu.netdisk-yCTMDER970GzYnBro9H_dg==/base.apk!classes30.dex:/data/app/~~B16CRjC1QDRuqT0GB9RRGA==/com.baidu.netdisk-yCTMDER970GzYnBro9H_dg==/base.apk!classes38.dex:/data/app/~~B16CRjC1QDRuqT0GB9RRGA==/com.baidu.netdisk-yCTMDER970GzYnBro9H_dg==/base.apk!classes16.dex:/data/app/~~B16CRjC1QDRuqT0GB9RRGA==/com.baidu.netdisk-yCTMDER970GzYnBro9H_dg==/base.apk!classes47.dex:/data/app/~~B16CRjC1QDRuqT0GB9RRGA==/com.baidu.netdisk-yCTMDER970GzYnBro9H_dg==/base.apk!classes50.dex:/data/app/~~B16CRjC1QDRuqT0GB9RRGA==/com.baidu.netdisk-yCTMDER970GzYnBro9H_dg==/base.apk!classes17.dex:/data/app/~~B16CRjC1QDRuqT0GB9RRGA==/com.baidu.netdisk-yCTMDER970GzYnBro9H_dg==/base.apk!classes27.dex:/data/app/~~B16CRjC1QDRuqT0GB9RRGA==/com.baidu.netdisk-yCTMDER970GzYnBro9H_dg==/base.apk!classes39.dex:/data/app/~~B16CRjC1QDRuqT0GB9RRGA==/com.baidu.netdisk-yCTMDER970GzYnBro9H_dg==/base.apk!classes22.dex], parent #1
#3 dalvik.system.PathClassLoader: [/product/app/WebViewGoogle/WebViewGoogle.apk], parent #1
#4 com.baidu.novel.cyberplayer.sdk._._: [/data/user/0/com.baidu.netdisk/files/cybermedia/libs/cyber-media-dex_7.5.2.10.jar], parent #2
#5 dalvik.system.PathClassLoader: [/system/app/MiuiContentCatcher/MiuiContentCatcher.apk], parent #1
#6 dalvik.system.PathClassLoader: [/system/app/CatcherPatch/CatcherPatch.apk], parent #1
#7 dalvik.system.PathClassLoader: [/system/framework/QXPerformance.jar], parent #0
#8 com.baidu.sofire.core.PluginloaderDexClassLoader: [/data/user/0/com.baidu.netdisk/files/.tmp/1-3.5.2.16.zip], parent #2
Done dumping class loaders
Classes initialized: 0 in 0
Intern table: 41950 strong; 1233 weak
JNI: CheckJNI is off; globals=569 (plus 152 weak)
Libraries: /data/app/~~B16CRjC1QDRuqT0GB9RRGA==/com.baidu.netdisk-yCTMDER970GzYnBro9H_dg==/lib/arm64/libBDPrecreate_V1_1.so /data/app/~~B16CRjC1QDRuqT0GB9RRGA==/com.baidu.netdisk-yCTMDER970GzYnBro9H_dg==/lib/arm64/libDnsChecker.so /data/app/~~B16CRjC1QDRuqT0GB9RRGA==/com.baidu.netdisk-yCTMDER970GzYnBro9H_dg==/lib/arm64/libbase64encoder_v2_0.so /data/app/~~B16CRjC1QDRuqT0GB9RRGA==/com.baidu.netdisk-yCTMDER970GzYnBro9H_dg==/lib/arm64/libbd_pass_face_sdk.so /data/app/~~B16CRjC1QDRuqT0GB9RRGA==/com.baidu.netdisk-yCTMDER970GzYnBro9H_dg==/lib/arm64/libbdtls.so /data/app/~~B16CRjC1QDRuqT0GB9RRGA==/com.baidu.netdisk-yCTMDER970GzYnBro9H_dg==/lib/arm64/libc++_shared.so /data/app/~~B16CRjC1QDRuqT0GB9RRGA==/com.baidu.netdisk-yCTMDER970GzYnBro9H_dg==/lib/arm64/libcrashpad_client.so /data/app/~~B16CRjC1QDRuqT0GB9RRGA==/com.baidu.netdisk-yCTMDER970GzYnBro9H_dg==/lib/arm64/libfire.so /data/app/~~B16CRjC1QDRuqT0GB9RRGA==/com.baidu.netdisk-yCTMDER970GzYnBro9H_dg==/lib/arm64/libimagepipeline.so /data/app/~~B16CRjC1QDRuqT0GB9RRGA==/com.baidu.netdisk-yCTMDER970GzYnBro9H_dg==/lib/arm64/libmagic_effects.so /data/app/~~B16CRjC1QDRuqT0GB9RRGA==/com.baidu.netdisk-yCTMDER970GzYnBro9H_dg==/lib/arm64/libmedia_player.so /data/app/~~B16CRjC1QDRuqT0GB9RRGA==/com.baidu.netdisk-yCTMDER970GzYnBro9H_dg==/lib/arm64/libmmkv.so /data/app/~~B16CRjC1QDRuqT0GB9RRGA==/com.baidu.netdisk-yCTMDER970GzYnBro9H_dg==/lib/arm64/libnative-crash.so /data/app/~~B16CRjC1QDRuqT0GB9RRGA==/com.baidu.netdisk-yCTMDER970GzYnBro9H_dg==/lib/arm64/libnetdisk-security.so /data/app/~~B16CRjC1QDRuqT0GB9RRGA==/com.baidu.netdisk-yCTMDER970GzYnBro9H_dg==/lib/arm64/libswanKV.so /data/app/~~B16CRjC1QDRuqT0GB9RRGA==/com.baidu.netdisk-yCTMDER970GzYnBro9H_dg==/lib/arm64/libtechain.so /data/app/~~B16CRjC1QDRuqT0GB9RRGA==/com.baidu.netdisk-yCTMDER970GzYnBro9H_dg==/lib/arm64/libvastcore.so /product/app/WebViewGoogle/WebViewGoogle.apk!/lib/arm64-v8a/libmonochrome.so /system/lib64/libwebviewchromium_plat_support.so libandroid.so libaudioeffect_jni.so libcompiler_rt.so libforcedarkimpl.so libframework-connectivity-jni.so libicu_jni.so libjavacore.so libjavacrypto.so libjnigraphics.so libmedia_jni.so libmiui_runtime.so libopenjdk.so libqti_performance.so librs_jni.so librtp_jni.so libsfplugin_ccodec.so libsoundpool.so libstats_jni.so libwebviewchromium_loader.so (38)
//堆使用情况
Heap: 6% free, 34MB(使用的heap大小)/36MB; 436248 objects
//concurrent copying GC信息:
Dumping cumulative Gc timings
Start Dumping Averages for 3 iterations for concurrent copying
ProcessMarkStack: Sum: 46.298ms Avg: 15.432ms
MarkingPhase: Sum: 38.970ms Avg: 12.990ms
ScanCardsForSpace: Sum: 34.527ms Avg: 11.509ms
ScanImmuneSpaces: Sum: 29.386ms Avg: 9.795ms
VisitConcurrentRoots: Sum: 12.565ms Avg: 4.188ms
ClearFromSpace: Sum: 10.284ms Avg: 3.428ms
CaptureThreadRootsForMarking: Sum: 5.357ms Avg: 1.785ms
FlipOtherThreads: Sum: 3.409ms Avg: 1.136ms
SweepLargeObjects: Sum: 1.455ms Avg: 485us
CopyingPhase: Sum: 1.312ms Avg: 437.333us
SweepSystemWeaks: Sum: 989us Avg: 329.666us
GrayAllDirtyImmuneObjects: Sum: 974us Avg: 324.666us
ProcessReferences: Sum: 873us Avg: 291us
InitializePhase: Sum: 519us Avg: 173us
EmptyRBMarkBitStack: Sum: 380us Avg: 126.666us
ThreadListFlip: Sum: 313us Avg: 104.333us
ReclaimPhase: Sum: 280us Avg: 93.333us
RecordFree: Sum: 261us Avg: 87us
ForwardSoftReferences: Sum: 235us Avg: 78.333us
EnqueueFinalizerReferences: Sum: 223us Avg: 74.333us
ResumeOtherThreads: Sum: 200us Avg: 66.666us
VisitNonThreadRoots: Sum: 159us Avg: 53us
ResumeRunnableThreads: Sum: 94us Avg: 31.333us
(Paused)ClearCards: Sum: 86us Avg: 28.666us
(Paused)GrayAllNewlyDirtyImmuneObjects: Sum: 59us Avg: 19.666us
MarkZygoteLargeObjects: Sum: 56us Avg: 18.666us
MarkStackAsLive: Sum: 51us Avg: 17us
SwapBitmaps: Sum: 49us Avg: 16.333us
SweepAllocSpace: Sum: 42us Avg: 14us
FlipThreadRoots: Sum: 9us Avg: 3us
Sweep: Sum: 8us Avg: 2.666us
UnBindBitmaps: Sum: 8us Avg: 2.666us
(Paused)SetFromSpace: Sum: 7us Avg: 2.333us
(Paused)FlipCallback: Sum: 6us Avg: 2us
Done Dumping Averages
//GC 暂时线程的时间信息
concurrent copying paused: Sum: 687us 99% C.I. 29us-215us Avg: 114.500us Max: 215us
concurrent copying freed-bytes: Avg: 7273KB Max: 12MB Min: 111KB
Freed-bytes histogram: 0:1,7680:1,12800:1
concurrent copying total time: 189.444ms mean time: 63.148ms
concurrent copying freed: 285552 objects with total size 21MB
concurrent copying throughput: 1.51086e+06/s / 112MB/s per cpu-time: 168015458/s / 160MB/s
concurrent copying tracing throughput: 107MB/s per cpu-time: 152MB/s
Average major GC reclaim bytes ratio 0.709386 over 3 GC cycles
Average major GC copied live bytes ratio 0.570257 over 7 major GCs
Cumulative bytes moved 37085336
Cumulative objects moved 680212
Peak regions allocated 91 (22MB) / 2048 (512MB)
Total madvise time 14.363ms
//young concurrent copying GC信息:
Start Dumping Averages for 6 iterations for young concurrent copying
ProcessMarkStack: Sum: 48.429ms Avg: 8.071ms
ScanImmuneSpaces: Sum: 29.178ms Avg: 4.863ms
ScanCardsForSpace: Sum: 16.210ms Avg: 2.701ms
VisitConcurrentRoots: Sum: 11.600ms Avg: 1.933ms
ClearFromSpace: Sum: 5.401ms Avg: 900.166us
ReclaimPhase: Sum: 3.908ms Avg: 651.333us
FlipOtherThreads: Sum: 3.542ms Avg: 590.333us
CopyingPhase: Sum: 2.319ms Avg: 386.500us
SweepSystemWeaks: Sum: 2.273ms Avg: 378.833us
InitializePhase: Sum: 2.170ms Avg: 361.666us
GrayAllDirtyImmuneObjects: Sum: 1.994ms Avg: 332.333us
SweepArray: Sum: 1.467ms Avg: 244.500us
EnqueueFinalizerReferences: Sum: 1.350ms Avg: 225us
ProcessReferences: Sum: 874us Avg: 145.666us
RecordFree: Sum: 478us Avg: 79.666us
ThreadListFlip: Sum: 453us Avg: 75.500us
ForwardSoftReferences: Sum: 252us Avg: 42us
EmptyRBMarkBitStack: Sum: 206us Avg: 34.333us
FlipThreadRoots: Sum: 180us Avg: 30us
VisitNonThreadRoots: Sum: 159us Avg: 26.500us
(Paused)SetFromSpace: Sum: 151us Avg: 25.166us
(Paused)ClearCards: Sum: 103us Avg: 17.166us
(Paused)GrayAllNewlyDirtyImmuneObjects: Sum: 97us Avg: 16.166us
ResumeRunnableThreads: Sum: 84us Avg: 14us
FreeList: Sum: 81us Avg: 13.500us
ResumeOtherThreads: Sum: 64us Avg: 10.666us
ResetStack: Sum: 47us Avg: 7.833us
MarkZygoteLargeObjects: Sum: 42us Avg: 7us
SwapBitmaps: Sum: 39us Avg: 6.500us
UnBindBitmaps: Sum: 28us Avg: 4.666us
(Paused)FlipCallback: Sum: 14us Avg: 2.333us
Done Dumping Averages
young concurrent copying paused: Sum: 1.344ms 99% C.I. 22us-267us Avg: 112us Max: 267us
young concurrent copying freed-bytes: Avg: 5053KB Max: 11MB Min: 1281KB
Freed-bytes histogram: 1280:2,2560:1,3840:1,6400:1,11520:1
young concurrent copying total time: 133.193ms mean time: 22.198ms
young concurrent copying freed: 427964 objects with total size 29MB
young concurrent copying throughput: 3.21777e+06/s / 222MB/s per cpu-time: 333916301/s / 318MB/s
young concurrent copying tracing throughput: 117MB/s per cpu-time: 167MB/s
Average minor GC reclaim bytes ratio 0.199116 over 6 GC cycles
Average minor GC copied live bytes ratio 0.183658 over 6 minor GCs
Cumulative bytes moved 5137256
Cumulative objects moved 75624
Peak regions allocated 91 (22MB) / 2048 (512MB)
Total time spent in GC: 322.637ms
Mean GC size throughput: 157MB/s per cpu-time: 225MB/s
Mean GC object throughput: 2.21151e+06 objects/s
Total number of allocations 1149764
Total bytes allocated 85MB
Total bytes freed 50MB
Free memory 2446KB
Free memory until GC 2446KB
Free memory until OOME 477MB
Total memory 36MB
Max memory 512MB
Zygote space size 7504KB
Total mutator paused time: 2.031ms
Total time waiting for GC to complete: 16.225ms
Total GC count: 9
Total GC time: 322.637ms
Total blocking GC count: 2
Total blocking GC time: 60.333ms
Histogram of GC count per 10000 ms: 0:1
Histogram of blocking GC count per 10000 ms: 0:1
Native bytes total: 73777825 registered: 1846817
Total native bytes at last GC: 51007561
/data/dalvik-cache/arm64/system@framework@QXPerformance.jar@classes.vdex: verify
/system/framework/oat/arm64/gson.odex: speed
/data/dalvik-cache/arm64/system@app@CatcherPatch@CatcherPatch.apk@classes.vdex: verify
/data/dalvik-cache/arm64/product@app@TrichromeLibrary@TrichromeLibrary.apk@classes.vdex: verify
/data/dalvik-cache/arm64/product@app@WebViewGoogle@WebViewGoogle.apk@classes.vdex: verify
/system/framework/oat/arm64/android.test.runner.vdex: verify
/data/app/~~B16CRjC1QDRuqT0GB9RRGA==/com.baidu.netdisk-yCTMDER970GzYnBro9H_dg==/oat/arm64/base.vdex: verify
/system/app/miuisystem/oat/arm64/miuisystem.vdex: verify
/data/dalvik-cache/arm64/system@app@MiuiContentCatcher@MiuiContentCatcher.apk@classes.vdex: verify
/system/framework/oat/arm64/android.test.mock.odex: verify
/data/dalvik-cache/arm64/system@priv-app@RtMiCloudSDK@RtMiCloudSDK.apk@classes.vdex: verify
/system/framework/oat/arm64/org.apache.http.legacy.odex: speed-profile
/system/app/miui/oat/arm64/miui.odex: verify
/system/framework/oat/arm64/android.hidl.base-V1.0-java.odex: verify
/system/framework/oat/arm64/android.hidl.manager-V1.0-java.odex: verify
/system/framework/oat/arm64/android.test.base.odex: verify
Current JIT code cache size (used / resident): 0KB / 0KB
Current JIT data cache size (used / resident): 0KB / 0KB
Zygote JIT code cache size (at point of fork): 13KB / 32KB
Zygote JIT data cache size (at point of fork): 17KB / 32KB
Current JIT mini-debug-info size: 15KB
Current JIT capacity: 0B
Current number of JIT JNI stub entries: 0
Current number of JIT code cache entries: 18
Total number of JIT baseline compilations: 0
Total number of JIT optimized compilations: 18
Total number of JIT compilations for on stack replacement: 0
Total number of JIT code cache collections: 0
Memory used for stack maps: Avg: 96B Max: 288B Min: 24B
Memory used for compiled code: Avg: 782B Max: 2468B Min: 148B
Memory used for profiling info: <no data>
Start Dumping Averages for 18 iterations for JIT timings
Compiling optimized: Sum: 31.455ms Avg: 1.747ms
TrimMaps: Sum: 767us Avg: 42.611us
Done Dumping Averages
Memory used for compilation: Avg: 101KB Max: 360KB Min: 19KB
ProfileSaver total_bytes_written=0
ProfileSaver total_number_of_writes=0
ProfileSaver total_number_of_code_cache_queries=0
ProfileSaver total_number_of_skipped_writes=0
ProfileSaver total_number_of_failed_writes=0
ProfileSaver total_ms_of_sleep=0
ProfileSaver total_ms_of_work=0
ProfileSaver total_number_of_hot_spikes=0
ProfileSaver total_number_of_wake_ups=0* ART internal metrics *Metadata:timestamp_since_start_ms: 5073Metrics:ClassLoadingTotalTime: count = 516190ClassVerificationTotalTime: count = 21109ClassVerificationCount: count = 16WorldStopTimeDuringGCAvg: count = 226YoungGcCount: count = 6FullGcCount: count = 3TotalBytesAllocated: count = 86718664TotalGcCollectionTime: count = 327YoungGcThroughputAvg: count = 140FullGcThroughputAvg: count = 77YoungGcTracingThroughputAvg: count = 124FullGcTracingThroughputAvg: count = 125JitMethodCompileTotalTime: count = 0JitMethodCompileCount: count = 0YoungGcCollectionTime: range = 0...60000, buckets: 6,0,0,0,0,0,0,0,0,0,0,0,0,0,0FullGcCollectionTime: range = 0...60000, buckets: 3,0,0,0,0,0,0,0,0,0,0,0,0,0,0YoungGcThroughput: range = 0...10000, buckets: 6,0,0,0,0,0,0,0,0,0,0,0,0,0,0FullGcThroughput: range = 0...10000, buckets: 3,0,0,0,0,0,0,0,0,0,0,0,0,0,0YoungGcTracingThroughput: range = 0...10000, buckets: 6,0,0,0,0,0,0,0,0,0,0,0,0,0,0FullGcTracingThroughput: range = 0...10000, buckets: 3,0,0,0,0,0,0,0,0,0,0,0,0,0,0
* Done dumping ART internal metrics *
Java 线程trace信息解读
//main(线程名)、prio(线程优先级,默认是5)、tid(线程唯一标识ID)、Sleeping(线程当前状态)
"main" prio=5 tid=1 Sleeping
//group: 线程所属的线程组sCount: 线程挂起次数dsCount: 用于调试的线程挂起次数
//obj: 当前线程关联的java线程对象 self: 当前线程地址
| group="main" sCount=1 dsCount=0 obj=0x73132d10 self=0x5598a5f5e0
//sysTid是线程号(主线程的线程号和进程号相同)
//nice: 调度优先级 cgrp: 进程所属的进程调度组 sched: 调度策略 handle: 函数处理地址
| sysTid=17027 nice=0 cgrp=default sched=0/0 handle=0x7fb6db6fe8
//state: 线程状态
//schedstat: CPU调度时间统计, 见proc/[pid]/task/[tid]/schedstat
//utm/stm: 用户态/内核态的CPU时间(单位是jiffies), 见proc/[pid]/task/[tid]/stat
//core: 该线程的最后运行所在核 HZ: 时钟频率
| state=S schedstat=( 420582038 5862546 143 ) utm=24 stm=18 core=6 HZ=100
//stack:线程栈的地址区间 stackSize:栈的大小
| stack=0x7fefba3000-0x7fefba5000 stackSize=8MB
//mutex: 所持有mutex类型,有独占锁exclusive和共享锁shared两类
| held mutexes=
// java堆栈调用信息(这里可查看导致ANR的代码调用流程)(分析ANR最重要的信息)
at java.lang.Thread.sleep!(Native method)
- sleeping on <0x0c60f3c7> (a java.lang.Object)
at java.lang.Thread.sleep(Thread.java:1031)
- locked <0x0c60f3c7> (a java.lang.Object) // 锁住对象0x0c60f3c7
at java.lang.Thread.sleep(Thread.java:985)
at android.os.SystemClock.sleep(SystemClock.java:120)
at org.code.ipc.MessengerService.onCreate(MessengerService.java:63) //导致ANR的代码
at android.app.ActivityThread.handleCreateService(ActivityThread.java:2877)
at android.app.ActivityThread.access$1900(ActivityThread.java:150)
at android.app.ActivityThread$H.handleMessage(ActivityThread.java:1427)
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)
Native线程trace信息解读
"Binder:5085_2" sysTid=5120
#00 pc 00000000000d11c4 /apex/com.android.runtime/lib64/bionic/libc.so (__ioctl+4) (BuildId: 6cb8b15ee5fadbb2232c4316a92a0abb)
#01 pc 000000000008b7ec /apex/com.android.runtime/lib64/bionic/libc.so (ioctl+132) (BuildId: 6cb8b15ee5fadbb2232c4316a92a0abb)
#02 pc 00000000000590ac /system/lib64/libbinder.so (android::IPCThreadState::talkWithDriver(bool)+244) (BuildId: bccc02121d3a0f422baf4bc787bd3a61)
#03 pc 0000000000059288 /system/lib64/libbinder.so (android::IPCThreadState::getAndExecuteCommand()+24) (BuildId: bccc02121d3a0f422baf4bc787bd3a61)
#04 pc 0000000000059a8c /system/lib64/libbinder.so (android::IPCThreadState::joinThreadPool(bool)+108) (BuildId: bccc02121d3a0f422baf4bc787bd3a61)
#05 pc 000000000007fb8c /system/lib64/libbinder.so (android::PoolThread::threadLoop()+24) (BuildId: bccc02121d3a0f422baf4bc787bd3a61)
#06 pc 0000000000013624 /system/lib64/libutils.so (android::Thread::_threadLoop(void)+328) (BuildId: f52e94e6224d7e15faba92ee0326b191)
#07 pc 00000000000c4cb8 /system/lib64/libandroid_runtime.so (android::AndroidRuntime::javaThreadShell(void)+140) (BuildId: 6b894f9477721e7dcbaeaaa57858fcc8)
#08 pc 00000000000e69d0 /apex/com.android.runtime/lib64/bionic/libc.so (__pthread_start(void*)+36) (BuildId: 6cb8b15ee5fadbb2232c4316a92a0abb)
#09 pc 0000000000084b6c /apex/com.android.runtime/lib64/bionic/libc.so (__start_thread+64) (BuildId: 6cb8b15ee5fadbb2232c4316a92a0abb)
Scout日志
Binder耗时日志
outgoing transaction: from {from_pid}:{from_tid} to {to_pid}:{to_tid} context:{binder/hwbinder} code:{code id} duration:{duration_time} s
incoming transaction: from {from_pid}:{from_tid} to {to_pid}:{to_tid} context:{binder/hwbinder} code:{code id} duration:{duration_time} s
pending transaction: from {from_pid}:{from_tid} to {to_pid}:{to_tid} context:{binder/hwbinder} code:{code id} duration:{duration_time} s
pending async transaction: from {from_pid}:{from_tid} to {to_pid}:{to_tid} context:{binder/hwbinder} code:{code id} duration:{duration_time} s
消息阻塞日志
- 打印当前正在阻塞的这条消息信息和最近20秒内处理的所有执行时长超过50ms的历史信息以及20秒内处理的消息数量
- 根据这个log,可以确认是当前消息耗时导致还是历史消息耗时,还是业务异常密集执行导致的ANR
06-22 15:16:10.133 10107 17131 29092 D ActivityThread: AnrScout get period history msg: (Current message: duration=7460ms seq=19329 late=17ms h=android.telecom.InCallService$1 w=5)
06-22 15:16:10.133 10107 17131 29092 D ActivityThread: AnrScout get period history msg:execute time>50ms (msgIndex=146 seq=18962 plan=15:15:54.662 late=87ms wall=60ms running=0ms h=android.telecom.InCallService$1 w=5)
06-22 15:16:10.133 10107 17131 29092 D ActivityThread: AnrScout get period history msg:execute time>50ms (msgIndex=142 seq=18958 plan=15:15:54.651 late=0ms wall=67ms running=0ms h=android.os.Handler c=android.telecom.Call$4)
06-22 15:16:10.133 10107 17131 29092 D ActivityThread: AnrScout get period history msg:In recent 20s, total historyMsgCount=512
日志解析: