赞
踩
ANR原理篇 - service/broadcast/provider超时机制
Build Info: 'alps-mp-r0.mp1:alps-mp-r0.mp1-V8.24.1_reallytek.r0mp1.k61v1.64.bsp_P138:mt6761:S01,TECNO/KF6h-GL/TECNO-KF6h:11/RP1A.200720.011/220711V496DevT:user/release-keys' MSSI Info: 'TECNO/TSSI/AGo-32:11/RP1A.200720.011/220711V349:user/release-keys' Exception Log Time:[Tue Feb 14 12:54:09 CST 2023] [22627.297038] Exception Class: ANR Exception Type: data_app_anr Current Executing Process: com.xxx.xxx com.xxx.xxx v6433 (6.4.33) Trigger time:[2023-02-14 12:54:09.261127] pid:406 Backtrace: Process: com.xxx.xxx PID: 406 UID: 10632 Flags: 0x30d83e44 Package: com.xxx.xxx v6433 (6.4.33) Foreground: Yes Process-Runtime: 8164728 Activity: com.xxx.xxx/com.xxx.ui.mall.activity.XxxWebActivity Subject: Input dispatching timed out (ActivityRecord{5e21df u0 com.xxx.xxx.lite/com.xxx.ui.mall.activity .XxxWebActivity t97310} does not have a focused window) Build: TECNO/KF6h-GL/TECNO-KF6h:11/RP1A.200720.011/220711V496DevT:user/release-keys ANR in com.xxx.xxx, time=29737782 Reason: executing service com.xxx.xxx/.service.XxxService //ANR原因 Load: 16.06 / 14.89 / 12.93 Android time :[2023-04-12 19:45:04.30] [29741.248] CPU usage from 94138ms to 0ms ago (2023-04-12 19:43:26.700 to 2023-04-12 19:45:00.838): 32% 30133/com.google.android.gms: 26% user + 5.8% kernel / faults: 156889 minor 30% 1002/system_server: 20% user + 10% kernel / faults: 33892 minor 13% 347/surfaceflinger: 6.6% user + 6.6% kernel / faults: 3476 minor 9.9% 1398/com.android.systemui: 8.1% user + 1.8% kernel / faults: 35960 minor 1 major 7.7% 15823/adbd: 1.9% user + 5.7% kernel / faults: 36366 minor 4.2% 222/mmcqd/0: 0% user + 4.2% kernel 3.4% 17495/com.android.defcontainer: 1.6% user + 1.7% kernel / faults: 1783 minor 3.4% 1565/tx_thread: 0% user + 3.4% kernel 3.3% 17461/com.android.settings: 2.4% user + 0.9% kernel / faults: 11452 minor 3.3% 220/exe_cq: 0% user + 3.3% kernel 3.2% 300/logd: 0.9% user + 2.3% kernel / faults: 76 minor 2.6% 346/servicemanager: 1% user + 1.5% kernel 2.5% 7889/com.google.android.gms.persistent: 2% user + 0.5% kernel / faults: 2454 minor 2.5% 216/hps_main: 0% user + 2.5% kernel 2.3% 481/installd: 0.1% user + 2.2% kernel 2.1% 451/aal: 0.7% user + 1.4% kernel 1.7% 454/media.codec: 1.1% user + 0.6% kernel / faults: 20602 minor 1.2% 15843/logcat: 0.5% user + 0.6% kernel 1.2% 1628/com.android.phone: 0.8% user + 0.3% kernel / faults: 410 minor 1.2% 15845/logcat: 0.5% user + 0.6% kernel 1% 3341/com.transsion.phoenix:service: 0.6% user + 0.3% kernel / faults: 2 minor 0.9% 590/akmd09911: 0.2% user + 0.7% kernel / faults: 6 minor 0.9% 2093/com.transsion.hilauncher: 0.7% user + 0.2% kernel / faults: 9318 minor 0.9% 417/disp_queue_P0: 0% user + 0.9% kernel 0.8% 17272/com.transsion.phoenix: 0.5% user + 0.2% kernel 0.6% 15154/kworker/u17:3: 0% user + 0.6% kernel 0.6% 12696/kworker/u17:2: 0% user + 0.6% kernel 0.6% 7/rcu_preempt: 0% user + 0.6% kernel 0.6% 8/rcu_sched: 0% user + 0.6% kernel 0.2% 11758/kworker/0:3: 0% user + 0.2% kernel 0.5% 74/ion_mm_heap: 0% user + 0.5% kernel 0.5% 3508/com.transsion.phonemaster: 0.3% user + 0.1% kernel / faults: 78 minor 0.5% 15503/kworker/u17:1: 0% user + 0.5% kernel 0.4% 13509/kworker/u16:0: 0% user + 0.4% kernel 0.4% 16252/kworker/u17:4: 0% user + 0.4% kernel 0.4% 806/com.android.vending: 0.4% user + 0% kernel / faults: 2258 minor 0.4% 15319/kworker/u16:2: 0% user + 0.4% kernel 0.4% 13884/kworker/u16:1: 0% user + 0.4% kernel 0.4% 14459/kworker/0:4: 0% user + 0.4% kernel 0.4% 16329/kworker/u16:5: 0% user + 0.4% kernel 0.3% 11433/kworker/0:5: 0% user + 0.3% kernel 0.3% 201/disp_delay_trig: 0% user + 0.3% kernel 0.3% 10/migration/0: 0% user + 0.3% kernel 0.3% 434/jbd2/dm-1-8: 0% user + 0.3% kernel 0.3% 69/dvfs_nfy: 0% user + 0.3% kernel 0.2% 11/migration/1: 0% user + 0.2% kernel 0.2% 398/dmcrypt_write: 0% user + 0.2% kernel 0.2% 17482/com.google.android.packageinstaller: 0.2% user + 0% kernel / faults: 928 minor 0.2% 486/netd: 0% user + 0.1% kernel / faults: 1273 minor 0.2% 17777/com.tencent.mobileqq:MSF: 0.1% user + 0% kernel / faults: 81 minor 0.2% 203/present_fence_w: 0% user + 0.2% kernel 0.2% 2232/kworker/1:2: 0% user + 0.2% kernel 0.2% 15/migration/2: 0% user + 0.2% kernel 0.2% 133/pbm: 0% user + 0.2% kernel 0% 15352/kworker/0:2: 0% user + 0% kernel 0.2% 73/cfinteractive: 0% user + 0.2% kernel 0.1% 23/migration/4: 0% user + 0.1% kernel 0.1% 14222/kworker/1:3: 0% user + 0.1% kernel 0.1% 14811/kworker/u16:3: 0% user + 0.1% kernel 0.1% 19/migration/3: 0% user + 0.1% kernel 0.1% 478/audioserver: 0% user + 0% kernel / faults: 162 minor 0.1% 15776/kworker/7:2: 0% user + 0.1% kernel 0.1% 27/migration/5: 0% user + 0.1% kernel 0.1% 348/mtkmal: 0.1% user + 0% kernel 0.1% 482/keystore: 0.1% user + 0% kernel 0.1% 31/migration/6: 0% user + 0.1% kernel 0.1% 247/charger_thread: 0% user + 0.1% kernel 0.1% 345/lmkd: 0% user + 0% kernel 0.1% 15775/kworker/5:0: 0% user 70% TOTAL: 38% user + 31% kernel + 0.2% iowait + 0.1% softirq ----- pid 12061 at 2023-04java-12 13:48:06 ----- Cmd line: com.xxx.xxx Build fingerprint: 'TECNO/H571/TECNO-AX8:7.0/NRD90M/B-190624V299:user/release-keys' ABI: 'arm64' Build type: optimized /** =====================类加载信息-开始 class_linker.cc中写入,记录类加载信息===================== */ Zygote loaded classes=16108 post zygote classes=9573 Dumping registered class loaders #0 dalvik.system.PathClassLoader: [], parent #1 #1 java.lang.BootClassLoader: [], no parent #2 dalvik.system.PathClassLoader: [/data/app/~~vbVFUHP-Q5oukq_bLiNj0w==/com.transsnet.boomplay.lite-R3xTRHDqhXkMGO0tbfFeGw==/base.apk:/data/app/~~vbVFUHP-Q5oukq_bLiNj0w==/com.transsnet.boomplay.lite-R3xTRHDqhXkMGO0tbfFeGw==/base.apk!classes2.dex:/data/app/~~vbVFUHP-Q5oukq_bLiNj0w==/com.transsnet.boomplay.lite-R3xTRHDqhXkMGO0tbfFeGw==/base.apk!classes3.dex], parent #1 #3 dalvik.system.InMemoryDexClassLoader: [/data/user/0/com.transsnet.boomplay.lite/Anonymous-DexFile@2764641574.jar], parent #2 #4 dalvik.system.DelegateLastClassLoader: [/data/user_de/0/com.google.android.gms/app_chimera/m/00000002/DynamiteLoader.apk], parent #0 #5 dalvik.system.DelegateLastClassLoader: [/data/user_de/0/com.google.android.gms/app_chimera/m/00000000/AdsDynamite.apk], parent #2 #6 dalvik.system.InMemoryDexClassLoader: [/data/user/0/com.transsnet.boomplay.lite/Anonymous-DexFile@3764699927.jar], parent #2 #7 dalvik.system.InMemoryDexClassLoader: [/data/user/0/com.transsnet.boomplay.lite/Anonymous-DexFile@1904604828.jar], parent #2 #8 dalvik.system.PathClassLoader: [/product/app/WebViewGoogle/WebViewGoogle.apk], parent #1 #9 dalvik.system.PathClassLoader: [/product/app/TrichromeLibrary/TrichromeLibrary.apk], parent #1 #10 dalvik.system.DexClassLoader: [/data/user/0/com.transsnet.boomplay.lite/cache/1658186039475.jar], parent #2 #11 dalvik.system.DexClassLoader: [/data/user/0/com.transsnet.boomplay.lite/app_pccache/2/BDA423607FA5C8DB48E6A852040B4F20FC43D4B8/pcam.jar], parent #2 Done dumping class loaders Classes initialized: 7610 in 6.478s /** =====================类加载信息-结束========================================================= */ /** =====================引用表-开始 intern_table.cc中写入,记录强弱引用数量===================== */ Intern table: 52569 strong; 653 weak /** =====================引用表-结束=========================================================== */ /** =====================JNI加载信息-开始 java_vm_ext.cc中写入,记录加载的so===================== */ JNI: CheckJNI is on; globals=537 (plus 272 weak) Libraries: /data/app/com.xxx.xxx-2/lib/arm64/libxxx.so /data/app/com.xxx.xxx-2/lib/arm64/libmmkv.so /system/lib64/libandroid.so /system/lib64/libcompiler_rt.so /system/lib64/libjavacrypto.so /system/lib64/libjnigraphics.so /system/lib64/libmedia_jni.so /system/lib64/libwebviewchromium_loader.so libjavacore.so libopenjdk.so (10) /** =====================JNI加载信息-结束====================================================== */ /** =====================java虚拟机堆状态-开始 heap.cc中写入,记录当前的内存状态===================== */ Heap: 1% free, 22MB/22MB; 75975 objects Dumping cumulative Gc timings Start Dumping histograms for 1 iterations for partial concurrent mark sweep ProcessMarkStack: Sum: 13.723ms 99% C.I. 0.101ms-13.010ms Avg: 4.574ms Max: 13.036ms MarkRootsCheckpoint: Sum: 12.257ms 99% C.I. 6.064ms-6.193ms Avg: 6.128ms Max: 6.193ms UpdateAndMarkImageModUnionTable: Sum: 9.253ms 99% C.I. 0.772us-5675us Avg: 544.294us Max: 6044us SweepMallocSpace: Sum: 5.684ms 99% C.I. 0.044ms-5.640ms Avg: 2.842ms Max: 5.640ms ScanGrayAllocSpaceObjects: Sum: 4.281ms 99% C.I. 0.002ms-4.257ms Avg: 2.140ms Max: 4.279ms UpdateAndMarkZygoteModUnionTable: Sum: 4.197ms 99% C.I. 4.197ms-4.197ms Avg: 4.197ms Max: 4.197ms AllocSpaceClearCards: Sum: 4.094ms 99% C.I. 0.001ms-3.971ms Avg: 1.023ms Max: 4.023ms MarkConcurrentRoots: Sum: 3.598ms 99% C.I. 0.565ms-3.025ms Avg: 1.799ms Max: 3.033ms (Paused)ScanGrayAllocSpaceObjects: Sum: 2.214ms 99% C.I. 0.004ms-2.210ms Avg: 1.107ms Max: 2.210ms ReMarkRoots: Sum: 1.367ms 99% C.I. 1.367ms-1.367ms Avg: 1.367ms Max: 1.367ms MarkAllocStackAsLive: Sum: 1.293ms 99% C.I. 1.293ms-1.293ms Avg: 1.293ms Max: 1.293ms ScanGrayImageSpaceObjects: Sum: 1.034ms 99% C.I. 0.283us-711.750us Avg: 60.823us Max: 722us (Paused)ScanGrayImageSpaceObjects: Sum: 738us 99% C.I. 0.265us-644.750us Avg: 43.411us Max: 686us (Paused)ProcessMarkStack: Sum: 225us 99% C.I. 225us-225us Avg: 225us Max: 225us SweepLargeObjects: Sum: 198us 99% C.I. 198us-198us Avg: 198us Max: 198us SweepSystemWeaks: Sum: 163us 99% C.I. 163us-163us Avg: 163us Max: 163us BindBitmaps: Sum: 113us 99% C.I. 113us-113us Avg: 113us Max: 113us MarkNonThreadRoots: Sum: 108us 99% C.I. 53us-55us Avg: 54us Max: 55us EnqueueFinalizerReferences: Sum: 105us 99% C.I. 105us-105us Avg: 105us Max: 105us ImageModUnionClearCards: Sum: 104us 99% C.I. 0.250us-39us Avg: 3.058us Max: 39us FinishPhase: Sum: 77us 99% C.I. 77us-77us Avg: 77us Max: 77us ProcessReferences: Sum: 59us 99% C.I. 59us-59us Avg: 59us Max: 59us ZygoteModUnionClearCards: Sum: 57us 99% C.I. 12us-45us Avg: 28.500us Max: 45us RevokeAllThreadLocalAllocationStacks: Sum: 51us 99% C.I. 51us-51us Avg: 51us Max: 51us MarkingPhase: Sum: 43us 99% C.I. 43us-43us Avg: 43us Max: 43us ReclaimPhase: Sum: 42us 99% C.I. 42us-42us Avg: 42us Max: 42us (Paused)PausePhase: Sum: 31us 99% C.I. 31us-31us Avg: 31us Max: 31us ProcessCards: Sum: 29us 99% C.I. 13us-16us Avg: 14.500us Max: 16us ScanGrayZygoteSpaceObjects: Sum: 25us 99% C.I. 25us-25us Avg: 25us Max: 25us PreCleanCards: Sum: 22us 99% C.I. 22us-22us Avg: 22us Max: 22us SwapBitmaps: Sum: 14us 99% C.I. 14us-14us Avg: 14us Max: 14us (Paused)ScanGrayZygoteSpaceObjects: Sum: 13us 99% C.I. 13us-13us Avg: 13us Max: 13us Sweep: Sum: 12us 99% C.I. 12us-12us Avg: 12us Max: 12us MarkRoots: Sum: 4us 99% C.I. 4us-4us Avg: 4us Max: 4us InitializePhase: Sum: 3us 99% C.I. 3us-3us Avg: 3us Max: 3us RecursiveMark: Sum: 2us 99% C.I. 2us-2us Avg: 2us Max: 2us SweepZygoteSpace: Sum: 1us 99% C.I. 1us-1us Avg: 1us Max: 1us FindDefaultSpaceBitmap: Sum: 0 99% C.I. 0ns-0ns Avg: 0ns Max: 0ns Done Dumping histograms partial concurrent mark sweep paused: Sum: 6.716ms 99% C.I. 6.716ms-6.716ms Avg: 6.716ms Max: 6.716ms partial concurrent mark sweep total time: 65.237ms mean time: 65.237ms partial concurrent mark sweep freed: 47501 objects with total size 5MB partial concurrent mark sweep throughput: 730785/s / 78MB/s Start Dumping histograms for 2 iterations for sticky concurrent mark sweep FreeList: Sum: 33.813ms 99% C.I. 4us-4566us Avg: 367.532us Max: 5846us MarkRootsCheckpoint: Sum: 29.286ms 99% C.I. 2.440ms-13.136ms Avg: 7.321ms Max: 13.198ms ScanGrayAllocSpaceObjects: Sum: 17.030ms 99% C.I. 0.002ms-10.912ms Avg: 2.128ms Max: 11.077ms ProcessMarkStack: Sum: 11.693ms 99% C.I. 0.001ms-6.876ms Avg: 1.461ms Max: 6.980ms SweepArray: Sum: 9.276ms 99% C.I. 2.812ms-6.464ms Avg: 4.638ms Max: 6.464ms MarkConcurrentRoots: Sum: 9.065ms 99% C.I. 0.010ms-6.326ms Avg: 2.266ms Max: 6.356ms ScanGrayImageSpaceObjects: Sum: 5.890ms 99% C.I. 0.288us-1678.999us Avg: 86.617us Max: 1864us MarkNonThreadRoots: Sum: 4.015ms 99% C.I. 0.045ms-3.775ms Avg: 1.003ms Max: 3.820ms ReMarkRoots: Sum: 2.579ms 99% C.I. 0.575ms-2.004ms Avg: 1.289ms Max: 2.004ms SweepSystemWeaks: Sum: 1.775ms 99% C.I. 315us-1460us Avg: 887.500us Max: 1460us (Paused)ScanGrayAllocSpaceObjects: Sum: 979us 99% C.I. 0.500us-883us Avg: 244.750us Max: 883us ScanGrayZygoteSpaceObjects: Sum: 951us 99% C.I. 11us-691us Avg: 237.750us Max: 692us MarkingPhase: Sum: 499us 99% C.I. 226us-273us Avg: 249.500us Max: 273us AllocSpaceClearCards: Sum: 457us 99% C.I. 0.333us-202us Avg: 57.125us Max: 202us BindBitmaps: Sum: 330us 99% C.I. 108us-222us Avg: 165us Max: 222us ImageModUnionClearCards: Sum: 258us 99% C.I. 0.253us-59us Avg: 3.794us Max: 59us ResetStack: Sum: 231us 99% C.I. 87us-144us Avg: 115.500us Max: 144us EnqueueFinalizerReferences: Sum: 171us 99% C.I. 20us-151us Avg: 85.500us Max: 151us ProcessReferences: Sum: 125us 99% C.I. 15us-110us Avg: 62.500us Max: 110us RevokeAllThreadLocalAllocationStacks: Sum: 121us 99% C.I. 37us-84us Avg: 60.500us Max: 84us ReclaimPhase: Sum: 111us 99% C.I. 26us-85us Avg: 55.500us Max: 85us (Paused)PausePhase: Sum: 109us 99% C.I. 35us-74us Avg: 54.500us Max: 74us FinishPhase: Sum: 82us 99% C.I. 32us-50us Avg: 41us Max: 50us ZygoteModUnionClearCards: Sum: 73us 99% C.I. 12us-27us Avg: 18.250us Max: 27us (Paused)ScanGrayImageSpaceObjects: Sum: 68us 99% C.I. 0.250us-21us Avg: 2us Max: 21us InitializePhase: Sum: 63us 99% C.I. 16us-47us Avg: 31.500us Max: 47us PreCleanCards: Sum: 51us 99% C.I. 23us-28us Avg: 25.500us Max: 28us (Paused)ProcessMarkStack: Sum: 45us 99% C.I. 1us-44us Avg: 22.500us Max: 44us SwapBitmaps: Sum: 29us 99% C.I. 10us-19us Avg: 14.500us Max: 19us ForwardSoftReferences: Sum: 20us 99% C.I. 3us-17us Avg: 10us Max: 17us (Paused)ScanGrayZygoteSpaceObjects: Sum: 18us 99% C.I. 7us-11us Avg: 9us Max: 11us MarkRoots: Sum: 11us 99% C.I. 5us-6us Avg: 5.500us Max: 6us UnBindBitmaps: Sum: 10us 99% C.I. 3us-7us Avg: 5us Max: 7us SwapStacks: Sum: 4us 99% C.I. 2us-2us Avg: 2us Max: 2us RecordFree: Sum: 3us 99% C.I. 1us-2us Avg: 1.500us Max: 2us FindDefaultSpaceBitmap: Sum: 2us 99% C.I. 1us-1us Avg: 1us Max: 1us PreSweepingGcVerification: Sum: 0 99% C.I. 0ns-0ns Avg: 0ns Max: 0ns Done Dumping histograms sticky concurrent mark sweep paused: Sum: 4.504ms 99% C.I. 2.035ms-2.469ms Avg: 2.252ms Max: 2.469ms sticky concurrent mark sweep total time: 129.294ms mean time: 64.647ms sticky concurrent mark sweep freed: 91166 objects with total size 6MB sticky concurrent mark sweep throughput: 706713/s / 51MB/s Total time spent in GC: 194.531ms Mean GC size throughput: 51MB/s Mean GC object throughput: 712498 objects/s /** 2.2 内存信息* start/ Total number of allocations 214578 Total bytes allocated 32MB Total bytes freed 10MB Free memory 335KB Free memory until GC 335KB Free memory until OOME 361MB Total memory 22MB Max memory 384MB /** 2.2 内存信息* end/ Zygote space size 1340KB Total mutator paused time: 11.220ms Total time waiting for GC to complete: 3.077us Total GC count: 3 Total GC time: 194.531ms Total blocking GC count: 0 Total blocking GC time: 0 Histogram of native allocation 0:1038,128:379,256:105,384:160,640:1,896:16,1152:2 bucket size 128 Histogram of native free 0:156,64:133,192:351,256:38,448:90,640:1 bucket size 64 /** =====================java虚拟机堆状态-结束====================================================== */ /** =====================OTA文件记录-开始 oat_file_manager.cc中写入,记录当前使用到的OTA文件===================== */ /data/user_de/0/com.google.android.gms/app_chimera/m/0000030c/oat/arm64/MeasurementDynamite.odex: speed /data/user/0/com.xxx.xxx/app_optimized/audience_network.dex: speed /system/framework/oat/arm64/com.android.location.provider.odex: speed /system/framework/oat/arm64/com.android.media.remotedisplay.odex: speed /data/app/com.google.android.gms-2/oat/arm64/base.odex: interpret-only /data/user_de/0/com.google.android.gms/app_chimera/m/00000307/oat/arm64/DynamiteLoader.odex: speed /data/user_de/0/com.google.android.gms/app_chimera/m/000002ee/oat/arm64/dl-AdsFdrDynamite.integ_230500000000000.odex: speed /data/app/com.xxx.xxx-2/oat/arm64/base.odex: interpret-only /** =====================OTA文件记录-结束===================================================================== */ /** =====================JIT信息记录-开始 jit.cc中写入,记录JIT的信息===================== */ Current JIT code cache size: 17KB Current JIT data cache size: 20KB Current JIT capacity: 64KB Current number of JIT code cache entries: 16 Total number of JIT compilations: 16 Total number of JIT compilations for on stack replacement: 0 Total number of deoptimizations: 0 Total number of JIT code cache collections: 0 Memory used for stack maps: Avg: 675B Max: 2992B Min: 64B Memory used for compiled code: Avg: 1081B Max: 2648B Min: 176B Memory used for profiling info: Avg: 274B Max: 1040B Min: 32B Start Dumping histograms for 16 iterations for JIT timings Compiling: Sum: 512.109ms 99% C.I. 3.640ms-96.064ms Avg: 32.006ms Max: 96.425ms TrimMaps: Sum: 12.116ms 99% C.I. 41us-5108us Avg: 757.250us Max: 5295us Done Dumping histograms Memory used for compilation: Avg: 346KB Max: 959KB Min: 77KB 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=2000 ProfileSaver total_ms_of_work=0 ProfileSaver total_number_of_foreign_dex_marks=2 ProfileSaver max_number_profile_entries_cached=19 ProfileSaver total_number_of_hot_spikes=0 ProfileSaver total_number_of_wake_ups=0 /** =====================JIT信息记录-结束================================================ */ /** =====================ART信息指标-开始 metrics_common.cc中写入,记录ART虚拟机的一些关键指标===================== */ *** ART internal metrics *** Metadata: timestamp_since_start_ms: 19952 Metrics: ClassLoadingTotalTime: count = 17358 ClassVerificationTotalTime: count = 15303 ClassVerificationCount: count = 28 WorldStopTimeDuringGCAvg: count = 0 YoungGcCount: count = 0 FullGcCount: count = 0 TotalBytesAllocated: count = 2349168 TotalGcCollectionTime: count = 0 YoungGcThroughputAvg: count = 0 FullGcThroughputAvg: count = 0 YoungGcTracingThroughputAvg: count = 0 FullGcTracingThroughputAvg: count = 0 JitMethodCompileTotalTime: count = 28492 JitMethodCompileCount: count = 39 YoungGcCollectionTime: range = 0...60000, buckets: 0,0,0,0,0,0,0,0,0,0,0,0,0,0,0 FullGcCollectionTime: range = 0...60000, buckets: 0,0,0,0,0,0,0,0,0,0,0,0,0,0,0 YoungGcThroughput: range = 0...10000, buckets: 0,0,0,0,0,0,0,0,0,0,0,0,0,0,0 FullGcThroughput: range = 0...10000, buckets: 0,0,0,0,0,0,0,0,0,0,0,0,0,0,0 YoungGcTracingThroughput: range = 0...10000, buckets: 0,0,0,0,0,0,0,0,0,0,0,0,0,0,0 FullGcTracingThroughput: range = 0...10000, buckets: 0,0,0,0,0,0,0,0,0,0,0,0,0,0,0 *** Done dumping ART internal metrics *** /** =====================ART信息指标-结束====================================================================== */ /** =====================线程信息-开始 thread_list.cc中写入,记录当前进程的线程信息============================== */ suspend all histogram: Sum: 2.785ms 99% C.I. 4us-1964.800us Avg: 278.500us Max: 2044us DALVIK THREADS (71): "Signal Catcher" daemon prio=5 tid=3 Runnable | group="system" sCount=0 dsCount=0 obj=0x12d555e0 self=0x7a8d897400 | sysTid=12067 nice=0 cgrp=default sched=0/0 handle=0x7a8cd04450 | state=R schedstat=( 53844613 20052004 79 ) utm=2 stm=2 core=0 HZ=100 | stack=0x7a8cc0a000-0x7a8cc0c000 stackSize=1005KB | held mutexes= "mutator lock"(shared held) native: #00 pc 000000000047c0fc /system/lib64/libart.so (_ZN3art15DumpNativeStackERNSt3__113basic_ostreamIcNS0_11char_traitsIcEEEEiP12BacktraceMapPKcPNS_9ArtMethodEPv+220) native: #01 pc 000000000047c0f8 /system/lib64/libart.so (_ZN3art15DumpNativeStackERNSt3__113basic_ostreamIcNS0_11char_traitsIcEEEEiP12BacktraceMapPKcPNS_9ArtMethodEPv+216) native: #02 pc 000000000045027c /system/lib64/libart.so (_ZNK3art6Thread9DumpStackERNSt3__113basic_ostreamIcNS1_11char_traitsIcEEEEbP12BacktraceMap+480) native: #03 pc 0000000000467de8 /system/lib64/libart.so (_ZN3art14DumpCheckpoint3RunEPNS_6ThreadE+832) native: #04 pc 00000000004600d4 /system/lib64/libart.so (_ZN3art10ThreadList13RunCheckpointEPNS_7ClosureE+476) native: #05 pc 000000000045fcc4 /system/lib64/libart.so (_ZN3art10ThreadList4DumpERNSt3__113basic_ostreamIcNS1_11char_traitsIcEEEEb+848) native: #06 pc 000000000045f930 /system/lib64/libart.so (_ZN3art10ThreadList14DumpForSigQuitERNSt3__113basic_ostreamIcNS1_11char_traitsIcEEEE+804) native: #07 pc 000000000043b8c4 /system/lib64/libart.so (_ZN3art7Runtime14DumpForSigQuitERNSt3__113basic_ostreamIcNS1_11char_traitsIcEEEE+344) native: #08 pc 0000000000441f44 /system/lib64/libart.so (_ZN3art13SignalCatcher13HandleSigQuitEv+2096) native: #09 pc 0000000000440aec /system/lib64/libart.so (_ZN3art13SignalCatcher3RunEPv+480) native: #10 pc 000000000006a31c /system/lib64/libc.so (_ZL15__pthread_startPv+208) native: #11 pc 000000000001db28 /system/lib64/libc.so (__start_thread+16) (no managed stack frames) "main" prio=5 tid=1 Blocked | group="main" sCount=1 dsCount=0 obj=0x75bc7c50 self=0x7a8d896a00 | sysTid=12061 nice=0 cgrp=default sched=0/0 handle=0x7a91e23a98 | state=S schedstat=( 401196933 229090000 643 ) utm=29 stm=10 core=4 HZ=100 | stack=0x7ff9366000-0x7ff9368000 stackSize=8MB | held mutexes= at android.app.SystemServiceRegistry$CachedServiceFetcher.getService(SystemServiceRegistry.java:929) - waiting to lock <0x077d5864> (a java.lang.Object[]) held by thread 23 at android.app.SystemServiceRegistry.getSystemService(SystemServiceRegistry.java:886) at android.app.ContextImpl.getSystemService(ContextImpl.java:1524) at android.content.ContextWrapper.getSystemService(ContextWrapper.java:659) at android.view.TouchScreenHelper.updateDisplayInfo(TouchScreenHelper.java:323) at android.view.TouchScreenHelper.init(TouchScreenHelper.java:149) at android.view.TouchScreenHelper.<init>(TouchScreenHelper.java:87) at android.view.WindowManagerGlobal.getTouchScreenHelper(WindowManagerGlobal.java:173) - locked <0x02a54acd> (a java.lang.Class<android.view.WindowManagerGlobal>) at com.android.internal.policy.DecorView.<init>(DecorView.java:290) at com.android.internal.policy.PhoneWindow.generateDecor(PhoneWindow.java:2376) at com.android.internal.policy.PhoneWindow.installDecor(PhoneWindow.java:2730) at com.android.internal.policy.PhoneWindow.getDecorView(PhoneWindow.java:2085) at com.xxx.common.base.XxxBaseActivity.toggleTranslucent(XxxBaseActivity.java:37) at com.xxx.common.base.XxxBaseActivity.onCreate(XxxBaseActivity.java:20) at com.xxx.xxx.guide.ControllerActivity.onCreate(ControllerActivity.java:174) at android.app.Activity.performCreate(Activity.java:6734) at android.app.Instrumentation.callActivityOnCreate(Instrumentation.java:1118) at android.app.ActivityThread.performLaunchActivity(ActivityThread.java:2681) at android.app.ActivityThread.handleLaunchActivity(ActivityThread.java:2793) at android.app.ActivityThread.-wrap12(ActivityThread.java:-1) at android.app.ActivityThread$H.handleMessage(ActivityThread.java:1527) at android.os.Handler.dispatchMessage(Handler.java:110) at android.os.Looper.loop(Looper.java:203) at android.app.ActivityThread.main(ActivityThread.java:6301) at java.lang.reflect.Method.invoke!(Native method) at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:1094) at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:955) "RxCachedThreadScheduler-1" daemon prio=5 tid=23 Blocked | group="main" sCount=1 dsCount=0 obj=0x12f61af0 self=0x7a8211fa00 | sysTid=12096 nice=0 cgrp=default sched=0/0 handle=0x7a68c66450 | state=S schedstat=( 164816616 182495075 396 ) utm=13 stm=2 core=7 HZ=100 | stack=0x7a68b64000-0x7a68b66000 stackSize=1037KB | held mutexes= at android.view.WindowManagerGlobal.getInstance(WindowManagerGlobal.java:182) - waiting to lock <0x02a54acd> (a java.lang.Class<android.view.WindowManagerGlobal>) held by thread 1 at android.view.WindowManagerImpl.<init>(WindowManagerImpl.java:58) at android.view.WindowManagerImpl.<init>(WindowManagerImpl.java:65) at android.app.SystemServiceRegistry$50.createService(SystemServiceRegistry.java:599) at android.app.SystemServiceRegistry$50.createService(SystemServiceRegistry.java:598) at android.app.SystemServiceRegistry$CachedServiceFetcher.getService(SystemServiceRegistry.java:933) - locked <0x077d5864> (a java.lang.Object[]) at android.app.SystemServiceRegistry.getSystemService(SystemServiceRegistry.java:886) at android.app.ContextImpl.getSystemService(ContextImpl.java:1524) at android.content.ContextWrapper.getSystemService(ContextWrapper.java:659) at me.jessyan.autosize.utils.ScreenUtils.getScreenSize(ScreenUtils.java:62) at me.jessyan.autosize.AutoSizeConfig.init(AutoSizeConfig.java:247) at me.jessyan.autosize.AutoSizeConfig.init(AutoSizeConfig.java:205) at me.jessyan.autosize.AutoSize.checkAndInit(AutoSize.java:84) at com.xxx.common.base.XxxApplicationInitor.initAutoSize(MusicApplicationInitor.java:404) at com.xxx.common.base.XxxApplicationInitor.thirdSDKInit(MusicApplicationInitor.java:414) at com.xxx.common.base.XxxApplicationInitor.preInit(MusicApplicationInitor.java:438) at com.xxx.common.base.XxxApplicationInitor.access$800(MusicApplicationInitor.java:109) at com.xxx.common.base.XxxApplicationInitor$10.subscribe(MusicApplicationInitor.java:231) at io.reactivex.internal.operators.observable.ObservableCreate.subscribeActual(ObservableCreate.java:40) at io.reactivex.Observable.subscribe(Observable.java:12284) at io.reactivex.internal.operators.observable.ObservableSubscribeOn$SubscribeTask.run(ObservableSubscribeOn.java:96) at io.reactivex.Scheduler$DisposeTask.run(Scheduler.java:578) at io.reactivex.internal.schedulers.ScheduledRunnable.run(ScheduledRunnable.java:66) at io.reactivex.internal.schedulers.ScheduledRunnable.call(ScheduledRunnable.java:57) at java.util.concurrent.FutureTask.run(FutureTask.java:237) at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:272) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1133) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:607) at java.lang.Thread.run(Thread.java:761) "Binder:1002_1" prio=5 tid=7 Native | group="main" sCount=1 dsCount=0 obj=0x12c01940 self=0x7a8d8c3400 | sysTid=1020 nice=0 cgrp=default sched=0/0 handle=0x7a869be450 | state=S schedstat=( 19616954905 44253949137 66794 ) utm=1314 stm=647 core=1 HZ=100 | stack=0x7a868c4000-0x7a868c6000 stackSize=1005KB | held mutexes= kernel: (couldn't read /proc/self/task/1020/stack) native: #00 pc 000000000006c840 /system/lib64/libc.so (__ioctl+4) native: #01 pc 000000000001fb60 /system/lib64/libc.so (ioctl+140) native: #02 pc 0000000000055698 /system/lib64/libbinder.so (_ZN7android14IPCThreadState14talkWithDriverEb+264) native: #03 pc 00000000000557fc /system/lib64/libbinder.so (_ZN7android14IPCThreadState20getAndExecuteCommandEv+24) native: #04 pc 0000000000055f4c /system/lib64/libbinder.so (_ZN7android14IPCThreadState14joinThreadPoolEb+72) native: #05 pc 00000000000739f8 /system/lib64/libbinder.so (???) native: #06 pc 0000000000012598 /system/lib64/libutils.so (_ZN7android6Thread11_threadLoopEPv+272) native: #07 pc 00000000000a2618 /system/lib64/libandroid_runtime.so (_ZN7android14AndroidRuntime15javaThreadShellEPv+128) native: #08 pc 000000000006a31c /system/lib64/libc.so (_ZL15__pthread_startPv+208) native: #09 pc 000000000001db28 /system/lib64/libc.so (__start_thread+16) (no managed stack frames) ... /** =====================线程信息-结束============================================================================*/
发生ANR的时候,系统会产生一份anr日志文件(手机的/data/anr 目录下,文件名称可能各厂商不一样,业内大多称呼为trace文件),内含如下几项重要信息。
Reason: executing service com.xxx.xxx/.service.XxxService
Load: 16.06 / 14.89 / 12.93
CPU usage from 0ms to 1130ms ago (2023-04-12 19:43:26.700 to 2023-04-12 19:44:56.838):
32% 30133/com.google.android.gms: 26% user + 5.8% kernel / faults: 156889 minor
30% 1002/system_server: 20% user + 10% kernel / faults: 33892 minor
........省略N行.....
70% TOTAL: 38% user + 31% kernel + 0.2% iowait + 0.7% irq + 0.1% softirq
如上所示:
名词解释:
注意:
iowait占比很高,意味着有很大可能,是io耗时导致ANR,具体进一步查看有没有进程faults major比较多。
单进程CPU的负载并不是以100%为上限,而是有几个核,就有百分之几百,如4核上限为400%。
Total number of allocations 214578 进程创建到现在一共创建了多少对象
Total bytes allocated 32MB 进程创建到现在一共申请了多少内存
Total bytes freed 10MB 进程创建到现在一共释放了多少内存
Free memory 335KB 不扩展堆的情况下可用的内存
Free memory until GC 335KB GC前的可用内存
Free memory until OOME 361MB OOM之前的可用内存
Total memory 22MB 当前总内存(已用+可用)
Max memory 384MB 进程最多能申请的内存
从含义可以得出结论:**Free memory until OOME **的值很小的时候,已经处于内存紧张状态。应用可能是占用了过多内存。
ps:如果ANR时间点前后,日志里有打印onTrimMemory,也可以作为内存紧张的一个参考判断
"Binder:1002_1" prio=5 tid=7 Native
| group="main" sCount=1 dsCount=0 obj=0x12c01940 self=0x7a8d8c3400
| sysTid=1020 nice=0 cgrp=default sched=0/0 handle=0x7a869be450
| state=S schedstat=( 19616954905 44253949137 66794 ) utm=1314 stm=647 core=1 HZ=100
| stack=0x7a868c4000-0x7a868c6000 stackSize=1005KB
| held mutexes=
参数解读说明:
nice值越小则优先级越高。此处nice=-0,可见优先级相对较高;
schedstat括号中的3个数字依次是Running、Runable、Switch,紧接着的是utm和stm
结论:utm + stm = schedstat第一个参数值。
堆栈信息中ANR发生的进程当前线程的状态,也是分析ANR问题的一个重要信息。
"main" prio=5 tid=1 Blocked | group="main" sCount=1 dsCount=0 obj=0x75bc7c50 self=0x7a8d896a00 | sysTid=12061 nice=0 cgrp=default sched=0/0 handle=0x7a91e23a98 | state=S schedstat=( 401196933 229090000 643 ) utm=29 stm=10 core=4 HZ=100 | stack=0x7ff9366000-0x7ff9368000 stackSize=8MB | held mutexes= at android.app.SystemServiceRegistry$CachedServiceFetcher.getService(SystemServiceRegistry.java:929) - waiting to lock <0x077d5864> (a java.lang.Object[]) held by thread 23 at android.app.SystemServiceRegistry.getSystemService(SystemServiceRegistry.java:886) at android.app.ContextImpl.getSystemService(ContextImpl.java:1524) at android.content.ContextWrapper.getSystemService(ContextWrapper.java:659) at android.view.TouchScreenHelper.updateDisplayInfo(TouchScreenHelper.java:323) at android.view.TouchScreenHelper.init(TouchScreenHelper.java:149) at android.view.TouchScreenHelper.<init>(TouchScreenHelper.java:87) at android.view.WindowManagerGlobal.getTouchScreenHelper(WindowManagerGlobal.java:173) - locked <0x02a54acd> (a java.lang.Class<android.view.WindowManagerGlobal>) at com.android.internal.policy.DecorView.<init>(DecorView.java:290) at com.android.internal.policy.PhoneWindow.generateDecor(PhoneWindow.java:2376) at com.android.internal.policy.PhoneWindow.installDecor(PhoneWindow.java:2730) at com.android.internal.policy.PhoneWindow.getDecorView(PhoneWindow.java:2085) at com.xxx.common.base.TransBaseActivity.toggleTranslucent(TransBaseActivity.java:37) at com.xxx.common.base.TransBaseActivity.onCreate(TransBaseActivity.java:20) at com.xxx.xxx.guide.ControllerActivity.onCreate(ControllerActivity.java:174) at android.app.Activity.performCreate(Activity.java:6734) at android.app.Instrumentation.callActivityOnCreate(Instrumentation.java:1118) at android.app.ActivityThread.performLaunchActivity(ActivityThread.java:2681) at android.app.ActivityThread.handleLaunchActivity(ActivityThread.java:2793) at android.app.ActivityThread.-wrap12(ActivityThread.java:-1) at android.app.ActivityThread$H.handleMessage(ActivityThread.java:1527) at android.os.Handler.dispatchMessage(Handler.java:110) at android.os.Looper.loop(Looper.java:203) at android.app.ActivityThread.main(ActivityThread.java:6301) at java.lang.reflect.Method.invoke!(Native method) at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:1094) at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:955) ........省略N行..... "Binder:1002_1" prio=5 tid=7 Native | group="main" sCount=1 dsCount=0 obj=0x12c01940 self=0x7a8d8c3400 | sysTid=1020 nice=0 cgrp=default sched=0/0 handle=0x7a869be450 | state=S schedstat=( 19616954905 44253949137 66794 ) utm=1314 stm=647 core=1 HZ=100 | stack=0x7a868c4000-0x7a868c6000 stackSize=1005KB | held mutexes= kernel: (couldn't read /proc/self/task/1020/stack) native: #00 pc 000000000006c840 /system/lib64/libc.so (__ioctl+4) native: #01 pc 000000000001fb60 /system/lib64/libc.so (ioctl+140) native: #02 pc 0000000000055698 /system/lib64/libbinder.so (_ZN7android14IPCThreadState14talkWithDriverEb+264) native: #03 pc 00000000000557fc /system/lib64/libbinder.so (_ZN7android14IPCThreadState20getAndExecuteCommandEv+24) native: #04 pc 0000000000055f4c /system/lib64/libbinder.so (_ZN7android14IPCThreadState14joinThreadPoolEb+72) native: #05 pc 00000000000739f8 /system/lib64/libbinder.so (???) native: #06 pc 0000000000012598 /system/lib64/libutils.so (_ZN7android6Thread11_threadLoopEPv+272) native: #07 pc 00000000000a2618 /system/lib64/libandroid_runtime.so (_ZN7android14AndroidRuntime15javaThreadShellEPv+128) native: #08 pc 000000000006a31c /system/lib64/libc.so (_ZL15__pthread_startPv+208) native: #09 pc 000000000001db28 /system/lib64/libc.so (__start_thread+16) (no managed stack frames)
如上日志所示,本文截取了两个线程信息,一个是主线程main,它的状态是Blocked。另一个是Binder:1002_1,它的状态是Native。
教科书上说线程状态有5种:新建、就绪、执行、阻塞、死亡。而Java中的线程状态有6种,6种状态都定义在:java.lang.Thread.State中:
对应解释如下:
如上trace文件中的状态不止包含上述状态,还包含native等状态,多出来的状态哪来的?
其实trace文件中的状态还包含了CPP代码中定义的状态,下面是一张对应关系表:
下面我们继续看这些常见状态的案例。
Tips:Java中状态:
"main" tid=1 systid=17151 blocked | waiting to lock <0x05dfb3bd> (java.lang.Object) held by thread 46 at android.app.ContextImpl.getExternalCacheDirs(ContextImpl.java:836) at android.content.ContextWrapper.getExternalCacheDirs(ContextWrapper.java:311) at androidx.core.content.ContextCompat$Api19Impl.getExternalCacheDirs(ContextCompat.java:840) at androidx.core.content.ContextCompat.getExternalCacheDirs(ContextCompat.java:459) at androidx.core.content.FileProvider.parsePathStrategy(FileProvider.java:696) at androidx.core.content.FileProvider.getPathStrategy(FileProvider.java:635) at androidx.core.content.FileProvider.attachInfo(FileProvider.java:416) at android.app.ActivityThread.installProvider(ActivityThread.java:7673) at android.app.ActivityThread.installContentProviders(ActivityThread.java:7209) at android.app.ActivityThread.handleBindApplication(ActivityThread.java:7121) at android.app.ActivityThread.access$1600(ActivityThread.java:268) at android.app.ActivityThread$H.handleMessage(ActivityThread.java:2056) at android.os.Handler.dispatchMessage(Handler.java:106) at android.os.Looper.loop(Looper.java:268) at android.app.ActivityThread.main(ActivityThread.java:8107) at java.lang.reflect.Method.invoke(Method.java) at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:627) at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:997)
…省略N行…
RxCachedThreadScheduler-4 tid=46 systid=17212 native at libcore.io.Linux.access(Linux.java) at libcore.io.ForwardingOs.access(ForwardingOs.java:72) at libcore.io.BlockGuardOs.access(BlockGuardOs.java:73) at libcore.io.ForwardingOs.access(ForwardingOs.java:72) at android.app.ActivityThread$AndroidOs.access(ActivityThread.java:7982) at java.io.UnixFileSystem.checkAccess(UnixFileSystem.java:281) at java.io.File.exists(File.java:815) at android.app.ContextImpl.ensureExternalDirsExistOrFilter(ContextImpl.java:3022) at android.app.ContextImpl.getExternalFilesDirs(ContextImpl.java:779) at android.app.ContextImpl.getExternalFilesDir(ContextImpl.java:768) at android.content.ContextWrapper.getExternalFilesDir(ContextWrapper.java:276) at com.xxx.storage.cache.ScopeStorageUtils.getBPRootDir(ScopeStorageUtils.java:121) at com.xxx.storage.cache.ScopeStorageUtils.getBPRootPath(ScopeStorageUtils.java:134) at com.xxx.storage.cache.ScopeStorageUtils.shouldUseScopeStorage(ScopeStorageUtils.java:49) at com.xxx.util.PhoneDeviceUtil.getXxLocalDir(PhoneDeviceUtil.java:881) at com.xxx.util.PhoneDeviceUtil.getCacheDirPath(PhoneDeviceUtil.java:914) at com.xxx.xx.download.db.FileDownloaderDBHelper.<init>(FileDownloaderDBHelper.java:43) at com.xxx.xx.download.db.FileDownloaderDB.initDBAndCheckUpdate(FileDownloaderDB.java:49) at com.xxx.xx.download.db.FileDownloaderDB.<init>(FileDownloaderDB.java:44) at com.xxx.xx.download.db.FileDownloaderDB.<init>(FileDownloaderDB.java:38) at com.xxx.xx.download.db.FileDownloaderDB$Holder.<clinit>(FileDownloaderDB.java:60) at com.xxx.xx.download.db.FileDownloaderDB.getInstance(FileDownloaderDB.java:65) at com.xxx.storage.cache.PlaylistDB.getDB(PlaylistDB.java:57) at com.xxx.storage.cache.PlaylistDB.query(PlaylistDB.java:349) at com.xxx.storage.cache.HistoryPlaylistCache.queryDB(HistoryPlaylistCache.java:192) at com.xxx.storage.cache.HistoryPlaylistCache.<init>(HistoryPlaylistCache.java:39) at com.xxx.storage.cache.ItemCache.init(ItemCache.java:151) at com.xxx.common.base.XxApplicationInitor.init1(XxApplicationInitor.java:285) at com.xxx.common.base.XxApplicationInitor.access$500(XxApplicationInitor.java:115) at com.xxx.common.base.XxApplicationInitor$4.subscribe(XxApplicationInitor.java:177) at io.reactivex.internal.operators.observable.ObservableCreate.subscribeActual(ObservableCreate.java:40) at io.reactivex.Observable.subscribe(Observable.java:12284) at io.reactivex.internal.operators.observable.ObservableSubscribeOn$SubscribeTask.run(ObservableSubscribeOn.java:96) at io.reactivex.Scheduler$DisposeTask.run(Scheduler.java:578) at io.reactivex.internal.schedulers.ScheduledRunnable.run(ScheduledRunnable.java:66) at io.reactivex.internal.schedulers.ScheduledRunnable.call(ScheduledRunnable.java:57) at java.util.concurrent.FutureTask.run(FutureTask.java:266) at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:301) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1167) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:641) at java.lang.Thread.run(Thread.java:923)
由示例可知当前主线程被thread 46所阻塞。
"main" prio=5 tid=1 Waiting | group="main" sCount=1 dsCount=0 flags=1 obj=0x70df6868 self=0xa7c3de00 | sysTid=8565 nice=0 cgrp=default sched=1073741825/1 handle=0xa8222dc0 | state=S schedstat=( 421005565 19181973 433 ) utm=25 stm=16 core=2 HZ=100 | stack=0xbe132000-0xbe134000 stackSize=8192KB | held mutexes= at b.a.b.c.a.l.v(:1) - waiting on <0x077aff1b> (a java.lang.Class<b.a.b.c.a.l>) at b.a.b.c.f.b.e(:6) at b.a.b.c.a.k.c(:60) at b.a.b.c.a.k.a(:6) at b.a.b.c.a.k.<clinit>(:1) at com.xxx.storage.cache.g1.V(:2) at com.xxx.storage.cache.q1.a(:20) at com.xxx.biz.remote.j.i(:113) at com.xxx.biz.remote.j.f(:6) at com.transsnet.xxx.lite.service.PlayerService$m.a(:5) at com.transsnet.xxx.lite.service.PlayerService$m.onChanged(:1) at com.jeremyliao.liveeventbus.LiveEventBus$ObserverWrapper.onChanged(LiveEventBus.java:3) at androidx.lifecycle.LiveData.considerNotify(LiveData.java:6) at androidx.lifecycle.LiveData.dispatchingValue(LiveData.java:8) at androidx.lifecycle.LiveData.setValue(LiveData.java:4) at androidx.lifecycle.MutableLiveData.setValue(MutableLiveData.java:1) at com.jeremyliao.liveeventbus.LiveEventBus$LiveEvent.postInternal(LiveEventBus.java:1) at com.jeremyliao.liveeventbus.LiveEventBus$LiveEvent.access$1800(LiveEventBus.java:1) at com.jeremyliao.liveeventbus.LiveEventBus$LiveEvent$PostValueTask.run(LiveEventBus.java:1) at android.os.Handler.handleCallback(Handler.java:883) at android.os.Handler.dispatchMessage(Handler.java:100) at android.os.Looper.loop(Looper.java:214) at android.app.ActivityThread.main(ActivityThread.java:7669) at java.lang.reflect.Method.invoke(Native method) at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:590) at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:936)
…省略N行…
"RxCachedThreadScheduler-2" daemon prio=5 tid=35 Waiting | group="main" sCount=1 dsCount=0 flags=1 obj=0x12d428b0 self=0x92201400 | sysTid=8619 nice=0 cgrp=default sched=0/0 handle=0x7cd13230 | state=S schedstat=( 392687759 254464345 648 ) utm=33 stm=6 core=0 HZ=100 | stack=0x7cc10000-0x7cc12000 stackSize=1040KB | held mutexes= at b.a.b.c.a.l.j(:4) - waiting on <0x01a76acd> (a java.lang.Class<b.a.b.c.a.k>) at b.a.b.c.a.l.<clinit>(:1) at b.a.b.c.a.l.b(:1) at com.xxx.common.base.r.t(:6) at com.xxx.common.base.r.k(:22) at com.xxx.common.base.r.d(:1) at com.xxx.common.base.k.a(:1) at io.reactivex.internal.operators.observable.w0.subscribeActual(:3) at io.reactivex.m.subscribe(:14) at io.reactivex.internal.operators.observable.g6$a.run(:1) at io.reactivex.u.run(:2) at io.reactivex.internal.schedulers.ScheduledRunnable.run(ScheduledRunnable.java:2) at io.reactivex.internal.schedulers.ScheduledRunnable.call(ScheduledRunnable.java:1) at java.util.concurrent.FutureTask.run(FutureTask.java:266) at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:301) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1167) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:641) at java.lang.Thread.run(Thread.java:919)
- waiting on <0x077aff1b> (a java.lang.Class<b.a.b.c.a.l>)
根据示例可知当前主线程在等待获取<0x077aff1b>,继而搜索<0x077aff1b>发现当前trace.txt中无结果;退而求其次,继续搜索b.a.b.c.a.l,发现thread-35中在同时访问b.a.b.c.a.l中线程安全的方法b.a.b.c.a.l.j
Tips:Java & C 共有状态:
"main" prio=5 tid=1 Runnable | group="main" sCount=0 dsCount=0 flags=0 obj=0x722c7448 self=0xb0f3de00 | sysTid=30043 nice=0 cgrp=default sched=1073741825/1 handle=0xb1539dc0 | state=R schedstat=( 6367575122 32733935 3055 ) utm=565 stm=70 core=0 HZ=100 | stack=0xbe581000-0xbe583000 stackSize=8192KB | held mutexes= "mutator lock"(shared held) native: #00 pc 00303e8b /apex/com.android.runtime/lib/libart.so (art::DumpNativeStack(std::__1::basic_ostream<char, std::__1::char_traits<char>>&, int, BacktraceMap*, char const*, art::ArtMethod*, void*, bool)+78) native: #01 pc 003af52b /apex/com.android.runtime/lib/libart.so (art::Thread::DumpStack(std::__1::basic_ostream<char, std::__1::char_traits<char>>&, bool, BacktraceMap*, bool) const+358) native: #02 pc 003abb73 /apex/com.android.runtime/lib/libart.so (art::Thread::Dump(std::__1::basic_ostream<char, std::__1::char_traits<char>>&, bool, BacktraceMap*, bool) const+34) native: #03 pc 003c4ccb /apex/com.android.runtime/lib/libart.so (art::DumpCheckpoint::Run(art::Thread*)+606) native: #04 pc 003aff61 /apex/com.android.runtime/lib/libart.so (art::Thread::RunCheckpointFunction()+128) native: #05 pc 0041ff45 /apex/com.android.runtime/lib/libart.so (art::JniMethodFastEnd(unsigned int, art::Thread*)+40) at java.lang.System.arraycopy(Native method) at d.a.i.put(:16) at com.bumptech.glide.util.CachedHashCodeArrayMap.put(CachedHashCodeArrayMap.java:2) at com.bumptech.glide.request.BaseRequestOptions.transform(BaseRequestOptions.java:23) at com.bumptech.glide.request.BaseRequestOptions.transform(BaseRequestOptions.java:15) at com.bumptech.glide.request.BaseRequestOptions.optionalTransform(BaseRequestOptions.java:4) at com.bumptech.glide.request.BaseRequestOptions.scaleOnlyTransform(BaseRequestOptions.java:3) at com.bumptech.glide.request.BaseRequestOptions.optionalScaleOnlyTransform(BaseRequestOptions.java:1) at com.bumptech.glide.request.BaseRequestOptions.optionalFitCenter(BaseRequestOptions.java:1) at com.xxx.util.glide.b.N(:1) at com.xxx.util.glide.b.optionalFitCenter(:1) at com.bumptech.glide.RequestBuilder.into(RequestBuilder.java:22) at e.a.b.b.b.e(:46) at e.a.b.b.b.g(:2) at com.xxx.kit.function.HomeLastPlayedView.f(HomeLastPlayedView.java:4) at com.xxx.kit.function.HomeLastPlayedView.b(HomeLastPlayedView.java:29) at com.xxx.kit.function.HomeLastPlayedView.g(HomeLastPlayedView.java:12) at com.xxx.ui.home.c.n1.A1(:4) at com.xxx.ui.home.c.n1.z1(:5) at com.xxx.ui.home.c.n1.D(:1) at com.chad.library.adapter.base.m.n0(:4) at com.chad.library.adapter.base.m.o0(:2) at com.chad.library.adapter.base.m.onBindViewHolder(:2) at androidx.recyclerview.widget.RecyclerView$h.bindViewHolder(:8) ...省略View绘制流程堆栈... at android.view.ViewRootImpl.doTraversal(ViewRootImpl.java:1840) at android.view.ViewRootImpl$TraversalRunnable.run(ViewRootImpl.java:7937) at android.view.Choreographer$CallbackRecord.run(Choreographer.java:980) at android.view.Choreographer.doCallbacks(Choreographer.java:804) at android.view.Choreographer.doFrame(Choreographer.java:739) at android.view.Choreographer$FrameDisplayEventReceiver.run(Choreographer.java:965) at android.os.Handler.handleCallback(Handler.java:883) at android.os.Handler.dispatchMessage(Handler.java:100) at android.os.Looper.loop(Looper.java:264) at android.app.ActivityThread.main(ActivityThread.java:7605) at java.lang.reflect.Method.invoke(Native method) at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:492) at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:980)
示例为C中Runnable状态,表示当前线程可运行或正在运行。
上述示例中main-主线程状态为Runnable,为什么还会发生ANR呢?
这是因为虽然当前主线程状态为Runnable,但是可能有其它频繁调度的任务,导致cpu资源不足,无法及时执行到当前主线程,这个等待时间超过了ANR等待阈值,则会触发ANR,故需排查当前是否有频繁执行的任务。
Tips:C中状态:
"main" prio=5 tid=1 Native | group="main" sCount=1 dsCount=0 flags=1 obj=0x71356448 self=0xad23de00 | sysTid=5281 nice=0 cgrp=default sched=1073741825/1 handle=0xad781dc0 | state=S schedstat=( 513647352614 2827621143 157445 ) utm=45497 stm=5867 core=0 HZ=100 | stack=0xbe6c9000-0xbe6cb000 stackSize=8192KB | held mutexes= kernel: (couldn't read /proc/self/task/5281/stack) native: #00 pc 0005a16c /apex/com.android.runtime/lib/bionic/libc.so (syscall+28) native: #01 pc 0005f58d /apex/com.android.runtime/lib/bionic/libc.so (__futex_wait_ex(void volatile*, bool, int, bool, timespec const*)+88) native: #02 pc 000a58ad /apex/com.android.runtime/lib/bionic/libc.so (pthread_cond_wait+32) native: #03 pc 0004dd89 /system/lib/libc++.so (std::__1::condition_variable::wait(std::__1::unique_lock<std::__1::mutex>&)+8) native: #04 pc 0004fbfb /system/lib/libc++.so (std::__1::__assoc_sub_state::copy()+54) native: #05 pc 0004fdd1 /system/lib/libc++.so (std::__1::future<void>::get()+10) native: #06 pc 0034e119 /system/lib/libhwui.so (android::uirenderer::renderthread::RenderProxy::destroyHardwareResources()+144) at android.graphics.HardwareRenderer.nDestroyHardwareResources(Native method) at android.graphics.HardwareRenderer.clearContent(HardwareRenderer.java:505) at android.view.ThreadedRenderer.destroyHardwareResources(ThreadedRenderer.java:456) at android.view.ViewRootImpl.destroyHardwareRenderer(ViewRootImpl.java:7503) at android.view.ViewRootImpl.dispatchDetachedFromWindow(ViewRootImpl.java:4362) at android.view.ViewRootImpl.doDie(ViewRootImpl.java:7424) - locked <0x02d4ecb5> (a android.view.ViewRootImpl) at android.view.ViewRootImpl.die(ViewRootImpl.java:7397) at android.view.WindowManagerGlobal.removeViewLocked(WindowManagerGlobal.java:490) at android.view.WindowManagerGlobal.removeView(WindowManagerGlobal.java:428) - locked <0x0dc61f4a> (a java.lang.Object) at android.view.WindowManagerImpl.removeViewImmediate(WindowManagerImpl.java:126) at android.app.Dialog.dismissDialog(Dialog.java:389) at android.app.Dialog.dismiss(Dialog.java:371) at com.xxx.kit.function.CommonDialog$35.onClick(CommonDialog.java:957) at android.view.View.performClick(View.java:7156) at android.view.View.performClickInternal(View.java:7129) at android.view.View.onKeyUp(View.java:14212) at android.view.KeyEvent.dispatch(KeyEvent.java:2833) at android.view.View.dispatchKeyEvent(View.java:13398) at android.view.ViewGroup.dispatchKeyEvent(ViewGroup.java:1921) at android.view.ViewGroup.dispatchKeyEvent(ViewGroup.java:1931) at android.view.ViewGroup.dispatchKeyEvent(ViewGroup.java:1931) at android.view.ViewGroup.dispatchKeyEvent(ViewGroup.java:1931) at com.android.internal.policy.DecorView.superDispatchKeyEvent(DecorView.java:457) at com.android.internal.policy.PhoneWindow.superDispatchKeyEvent(PhoneWindow.java:1849) at android.app.Dialog.dispatchKeyEvent(Dialog.java:825) at com.android.internal.policy.DecorView.dispatchKeyEvent(DecorView.java:371) at android.view.ViewRootImpl$ViewPostImeInputStage.processKeyEvent(ViewRootImpl.java:5640) at android.view.ViewRootImpl$ViewPostImeInputStage.onProcess(ViewRootImpl.java:5503) at android.view.ViewRootImpl$InputStage.deliver(ViewRootImpl.java:5006) at android.view.ViewRootImpl$InputStage.onDeliverToNext(ViewRootImpl.java:5059) at android.view.ViewRootImpl$InputStage.forward(ViewRootImpl.java:5025) at android.view.ViewRootImpl$AsyncInputStage.forward(ViewRootImpl.java:5165) at android.view.ViewRootImpl$InputStage.apply(ViewRootImpl.java:5033) at android.view.ViewRootImpl$AsyncInputStage.apply(ViewRootImpl.java:5222) at android.view.ViewRootImpl$InputStage.deliver(ViewRootImpl.java:5006) at android.view.ViewRootImpl$InputStage.onDeliverToNext(ViewRootImpl.java:5059) at android.view.ViewRootImpl$InputStage.forward(ViewRootImpl.java:5025) at android.view.ViewRootImpl$InputStage.apply(ViewRootImpl.java:5033) at android.view.ViewRootImpl$InputStage.deliver(ViewRootImpl.java:5006) at android.view.ViewRootImpl$InputStage.onDeliverToNext(ViewRootImpl.java:5059) at android.view.ViewRootImpl$InputStage.forward(ViewRootImpl.java:5025) at android.view.ViewRootImpl$AsyncInputStage.forward(ViewRootImpl.java:5198) at android.view.ViewRootImpl$ImeInputStage.onFinishedInputEvent(ViewRootImpl.java:5363) at android.view.inputmethod.InputMethodManager$PendingEvent.run(InputMethodManager.java:3064) at android.view.inputmethod.InputMethodManager.invokeFinishedInputEventCallback(InputMethodManager.java:2607) at android.view.inputmethod.InputMethodManager.finishedInputEvent(InputMethodManager.java:2598) at android.view.inputmethod.InputMethodManager$ImeInputEventSender.onInputEventFinished(InputMethodManager.java:3041) at android.view.InputEventSender.dispatchInputEventFinished(InputEventSender.java:143) at android.os.MessageQueue.nativePollOnce(Native method) at android.os.MessageQueue.next(MessageQueue.java:336) at android.os.Looper.loop(Looper.java:215) at android.app.ActivityThread.main(ActivityThread.java:7605) at java.lang.reflect.Method.invoke(Native method) at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:492) at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:980)
Native状态–表示当前线程正在执行native层,C中代码。
Native状态仅凭当前主线程堆栈,无法判定引起ANR的原因就是当前捕获堆栈,需要结合mainlog排查发生ANR时间点前后执行的任务信息,进一步分析确定。
Copyright © 2003-2013 www.wpsshop.cn 版权所有,并保留所有权利。