android开关核进程迁移导致游戏卡顿记录

1. 背景

捕鱼达人游戏老化测试时出现游戏卡顿；

现场：

<idle>-0 [001] d.s4 3931.304437: cpufreq_interactive_target: cpu=1 load=78 cur=1104000 actual=1104000 targ=1008000 <idle>-0 [000] d.s4 3931.304442: cpufreq_interactive_target: cpu=0 load=20 cur=1104000 actual=1104000 targ=480000 cfinteractive-891 [000] …1 3931.306822: cpufreq_interactive_setspeed: cpu=0 targ=480000 actual=1008000 cfinteractive-891 [000] …1 3931.306825: cpufreq_interactive_setspeed: cpu=1 targ=1008000 actual=1008000 GLThread 55-5768 [001] d.s3 3931.324129: cpufreq_interactive_notyet: cpu=1 load=41 cur=1008000 actual=1008000 targ=480000 <idle>-0 [000] d.s4 3931.324136: cpufreq_interactive_target: cpu=0 load=123 cur=480000 actual=1008000 targ=1104000 cfinteractive-891 [000] …1 3931.326426: cpufreq_interactive_setspeed: cpu=0 targ=1104000 actual=1104000 <idle>-0 [001] d.s4 3931.402844: cpufreq_interactive_already: cpu=1 load=86 cur=1008000 actual=1104000 targ=1008000 .vorbis.decoder-4994 [000] d.s3 3931.402850: cpufreq_interactive_notyet: cpu=0 load=35 cur=1104000 actual=1104000 targ=480000 busybox-smp-7536 [001] d.s3 3931.422538: cpufreq_interactive_notyet: cpu=1 load=47 cur=1008000 actual=1104000 targ=600000 GLThread 55-5768 [000] dNs3 3931.422545: cpufreq_interactive_target: cpu=0 load=53 cur=1104000 actual=1104000 targ=720000 cfinteractive-891 [000] …1 3931.424856: cpufreq_interactive_setspeed: cpu=0 targ=720000 actual=1008000 <idle>-0 [001] d.s5 3931.501238: cpufreq_interactive_target: cpu=1 load=48 cur=1008000 actual=1104000 targ=600000 <idle>-0 [000] d.s4 3931.501245: cpufreq_interactive_notyet: cpu=0 load=61 cur=1104000 actual=1104000 targ=816000

分析后卡顿有两方面影响

2 开核 + 线程迁移 耗时造成的卡顿

游戏正常运行时需要捕鱼达人运行时cpu负载和频点分布，

————————-H64 CPU[x]<Freq:MHZ>-<Usage:%>————————- CPU0 CPU1 CPU2 CPU3 Temp GPU DDR Times |1104 55%| |1104 41%| | 0 0%| | 0 0%| 69 456 672 80 |1008 48%| |1008 50%| | 0 0%| | 0 0%| 69 456 672 81 | 720 45%| | 720 60%| | 0 0%| | 0 0%| 69 456 672 87 |1008 36%| |1008 58%| | 0 0%| | 0 0%| 69 456 672 88 |1104 61%| |1104 57%| | 0 0%| | 0 0%| 68 456 672 93

游戏过程中，突然弹出UI时，负载猛增，cpu负载上升，从等待开核到smp均衡完负载迁移期间，发生了卡顿，

使用cpu_monitor -s 50 ，每50ms为周期，观察cpu开关核和调频的过程变化，整个过程大约需要500ms

————————-H64 CPU[x]<Freq:MHZ>-<Usage:%>————————- CPU0 CPU1 CPU2 CPU3 Temp GPU DDR Times |1104 80%| | 0 0%| |1104 50%| | 0 0%| 75 456 672 214 |1104 100%| | 0 0%| |1104 83%| | 0 0%| 75 456 672 215 |1104 75%| |1104 0%| |1104 100%| | 0 0%| 75 456 672 216 |1104 20%| |1104 0%| |1104 80%| | 0 0%| 75 456 672 217 |1104 0%| |1104 0%| |1104 80%| | 0 0%| 74 456 672 218 |1104 25%| |1104 0%| |1104 50%| | 0 0%| 74 456 672 219 |1104 50%| |1104 16%| |1104 20%| | 0 0%| 74 456 672 220 |1104 25%| |1104 20%| |1104 60%| | 0 0%| 74 456 672 221 |1104 20%| |1104 0%| |1104 50%| | 0 0%| 74 456 672 222 |1104 20%| |1104 50%| |1104 40%| | 0 0%| 74 456 672 223

通过trace分析发现，从cpu 负载上升，到cpu autohotplug开核，经历了545ms

<idle>-0 [000] d.s4 3936.027644: cpufreq_interactive_already: cpu=0 load=83 cur=1104000 actual=1104000 targ=1104000 fishingjoy3.wdj-5723 [001] d.s4 3936.047351: cpufreq_interactive_target: cpu=1 load=106 cur=480000 actual=1104000 targ=1104000 …… autohotplug-892 [001] …1 3936.592662: autohotplug_operate: cpu=2 up=1 3. 游戏的卡顿，另一点是来自于.vorbis.decoder的负载突然猛增造成的

通过cpu_monitor工具发现，cpu 1~3 freq 720~1104 即可满足游戏最大场景负载.

当vorbis.decoder 进程负载猛增到25%~48%，cpu整体负载上升，这个时候又会去遇到问题1,这个问题先排查下.vorbis.decoder中处理是否存在问题，否则音频这部分问题的造成的卡顿会影响到所有的APK应用.

通过top工具简单分析发现，在捕鱼达人卡顿的时候，mediaserver进程负载很高，规律必现游戏卡顿时：

Mem: 966364K used, 34220K free, 0K shrd, 17520K buff, 457600K cachedd.defc CPU: 44.2% usr 11.9% sys 0.4% nic 42.3% idle 0.4% io 0.0% irq 0.4% sirq Load average: 3.36 3.31 2.41 1/702 25153 [7m PID PPID USER STAT VSZ %VSZ CPU %CPU COMMAND[0m 1757 1 1013 S 167m 16.9 0 31.7 /system/bin/mediaserver 3983 1768 10029 S < 1888m191.7 0 7.3 {IAPNativeWrappe} org.cocos2d.fish 3197 1768 10020 S N 1497m152.0 1 1.8 {m.starcor.hunan} com.starcor.huna 4061 4060 10029 S < 1470m149.3 0 1.8 {fishingjoy3.wdj} org.cocos2d.fish 4060 3983 10029 S < 1470m149.3 0 1.8 {fishingjoy3.wdj} org.cocos2d.fish 1674 1 1036 S 21112 2.0 0 1.8 /system/bin/logd 23277 23218 0 R 1256 0.1 0 1.3 busybox-smp top -d 1 1679 1 1000 S < 78444 7.7 1 0.9 /system/bin/surfaceflinger 2209 1767 1000 S < 2115m214.8 1 0.4 system_server 2072 1680 0 S 9956 0.9 0 0.4 logcat -v time 2517 1767 10010 S 2050m208.2 0 0.0 {ndroid.systemui} com.android.syst 2815 1767 10018 S 2050m208.2 0 0.0 {er.firelauncher} com.softwinner.f 2750 1767 10021 S 2031m206.3 1 0.0 {putmethod.latin} com.android.inpu 3233 1767 10026 S 2020m205.2 1 0.0 {ftwinner.update} com.softwinner.u 2895 1767 10001 S 2019m205.1 0 0.0 {d.process.acore} android.process. 2458 1767 10006 S 2017m204.9 1 0.0 {d.process.media} android.process. 3768 1767 10002 S 2014m204.5 0 0.0 {id.defcontainer} com.android.defc 3792 1767 10004 S 2014m204.5 1 0.0 {rtnercustomizer} com.google.andro 1767 1 0 S 2006m203.7 2 0.0 {main} zygote64

游戏正常运行时：

Mem: 965496K used, 35088K free, 0K shrd, 17520K buff, 457608K cachedblue CPU: 40.5% usr 48.9% sys 1.3% nic 8.3% idle 0.0% io 0.0% irq 0.6% sirq Load average: 3.36 3.31 2.41 1/699 25195 [7m PID PPID USER STAT VSZ %VSZ CPU %CPU COMMAND[0m 3983 1768 10029 S < 1889m191.9 0 25.8 {IAPNativeWrappe} org.cocos2d.fish 1679 1 1000 R < 78444 7.7 1 6.2 /system/bin/surfaceflinger 4060 3983 10029 S < 1470m149.3 0 5.5 {fishingjoy3.wdj} org.cocos2d.fish 3197 1768 10020 S N 1497m152.0 1 4.8 {m.starcor.hunan} com.starcor.huna 4061 4060 10029 S < 1470m149.3 0 4.8 {fishingjoy3.wdj} org.cocos2d.fish 1757 1 1013 S 167m 16.9 0 3.4 /system/bin/mediaserver 1145 1 0 S 9056 0.9 0 2.1 /sbin/ueventd 23277 23218 0 R 1256 0.1 1 2.1 busybox-smp top -d 1 2209 1767 1000 S < 2115m214.8 1 1.4 system_server 1674 1 1036 S 21112 2.0 0 1.4 /system/bin/logd 694 2 0 SW 0 0.0 0 1.4 [vsync proc 0] 1752 1 0 S 24832 2.4 0 0.7 /system/bin/netd 1760 1 0 S 8808 0.8 0 0.7 /system/bin/multi_ir 2600 2 0 SW 0 0.0 0 0.7 [ksdioirqd/mmc2] 653 2 0 SW 0 0.0 0 0.7 [kworker/0:2] 891 2 0 SW 0 0.0 0 0.7 [cfinteractive] 1116 2 0 SW 0 0.0 0 0.7 [tve detect] 892 2 0 SW 0 0.0 0 0.7 [autohotplug] 3614 2 0 SW 0 0.0 0 0.7 [kworker/u8:3] ^C517 1767 10010 S 2050m208.2 0 0.0 {ndroid.systemui} com.android.syst

游戏卡顿时发现/system/bin/mediaserver进程负载猛增，查一下原因，通过debuggerd -b busybox pidof mediaserver

通过debuggerd发现，mediaserver主进程中只有.vorbis.decoder 子线程是处于active状态，目前怀疑该进程负载猛增，影响到了游戏.

“.vorbis.decoder” sysTid=8748 #00 pc 00009274 /system/lib/libvorbisidec.so (mdct_backward+4348) #01 pc 0000813c /system/lib/libvorbisidec.so (mapping_inverse+1116) #02 pc 000049ec /system/lib/libvorbisidec.so (vorbis_dsp_synthesis+536) #03 pc 00002e2f /system/lib/libstagefright_soft_vorbisdec.so (android::SoftVorbis::onQueueFilled(unsigned int)+438) #04 pc 00016d41 /system/lib/libstagefright_omx.so (android::SimpleSoftOMXComponent::onMessageReceived(android::sp<android::AMessage> const&)+220) #05 pc 00016e87 /system/lib/libstagefright_omx.so #06 pc 0000c4c3 /system/lib/libstagefright_foundation.so (android::ALooperRoster::deliverMessage(android::sp<android::AMessage> const&)+166) #07 pc 0000be45 /system/lib/libstagefright_foundation.so (android::ALooper::loop()+220) #08 pc 000104d5 /system/lib/libutils.so (android::Thread::_threadLoop(void*)+112) #09 pc 00010045 /system/lib/libutils.so #10 pc 00016fd7 /system/lib/libc.so (__pthread_start(void*)+30) #11 pc 00014f1b /system/lib/libc.so (__start_thread+6)