vsync-app 不稳定导致抖动

问题描述：跟对比机器对比uc 浏览器新闻页滑动场景，出现抖动

1、trace 看是没有丢帧，对比看送帧buffer 给到 SF 步调不够一致，从间隔较大的两个 送帧buffer看，发现vsync-app 时间比正常的要长3ms 左右，vsync-app 不稳定。

从出现 vsync-app 不稳定帧，到下一个vsync-app ，看TimerDispatch 唤醒关系，已知的有两种情况：

1、 crtc_commit =》唤醒TimerDispatch（唤醒关系trace 上这里是不准的）

截图TimerDispatch 唤醒：

crtc_commit:161 992-992     (    992) [001] d.h.   345.231339: softirq_raise: vec=1 [action=TIMER]
crtc_commit:161 992-992     (    992) [001] d.h.   345.231341: softirq_raise: vec=9 [action=RCU]
crtc_commit:161 992-992     (    992) [001] d.h5   345.231371: sched_waking: comm=TimerDispatch pid=2689 prio=97 target_cpu=001
crtc_commit:161 992-992     (    992) [001] d.h6   345.231401: ipi_raise: target_mask=00000000,00000004 (Rescheduling interrupts)
          <idle>-0       (-------) [002] dn.1   345.231406: cpu_idle: state=4294967295 cpu_id=2
crtc_commit:161 992-992     (    992) [001] d.h6   345.231406: sched_wakeup: comm=TimerDispatch pid=2689 prio=97 target_cpu=002

crtc_commit:161 992-992     (    992) [001] d.h5   345.231371: sched_waking: comm=TimerDispatch pid=2689 prio=97 target_cpu=001

                       crtc_commit:161 992-992     (    992) [001] d.h5   345.231371: sched_waking: comm=TimerDispatch pid=2689 prio=97 target_cpu=001

                                    crtc_commit:161 992-992     (    992) [001] d.H.   345.231420: irq_handler_entry: irq=211 name=kgsl_3d0_irq
          <idle>-0       (-------) [002] d..2   345.231426: sched_switch: prev_comm=swapper/2 prev_pid=0 prev_prio=120 prev_state=R ==> next_comm=TimerDispatch next_pid=2689 next_prio=97

截图唤醒及紧接着2 处 TimerDispatch 唤醒

crtc_commit:161 992-992     (    992) [001] d.H.   345.231420: irq_handler_entry: irq=211 name=kgsl_3d0_irq
          <idle>-0       (-------) [002] d..2   345.231426: sched_switch: prev_comm=swapper/2 prev_pid=0 prev_prio=120 prev_state=R ==> next_comm=TimerDispatch next_pid=2689 next_prio=97

VizCompositor 9171-9171    (   8471) [000] d..2   345.233571: sched_waking: comm=Compositor pid=8886 prio=116 target_cpu=005
          <idle>-0       (-------) [003] d..2   345.233574: sched_switch: prev_comm=swapper/3 prev_pid=0 prev_prio=120 prev_state=R ==> next_comm=TimerDispatch next_pid=2689 next_prio=97

crtc_commit:161 992-992     (    992) [000] ....   345.239369: sde_evtlog: 992|sde_encoder_phys_cmd_prepare_for_kickoff:1574|0x39|0x0|0x1|0x0|0x2|0x0|0x0|0x0|0x0|0x0|0x0|0x0|0x0|0x0|0x0
          <idle>-0       (-------) [002] d..2   345.239369: sched_switch: prev_comm=swapper/2 prev_pid=0 prev_prio=120 prev_state=R ==> next_comm=TimerDispatch next_pid=2689 next_prio=97

2、 swapper =》唤醒TimerDispatch （定时中断唤醒）

这一次唤醒关系

Chrome_ChildIOT 8871-8871    (   8471) [000] d..6   345.099259: sched_wakeup: comm=VizCompositor pid=9171 prio=116 target_cpu=003
          <idle>-0       (-------) [001] dnh1   345.099260: softirq_raise: vec=1 [action=TIMER]
          <idle>-0       (-------) [002] d..1   345.099260: cpu_idle: state=0 cpu_id=2
          <idle>-0       (-------) [001] dnh1   345.099263: softirq_raise: vec=9 [action=RCU]
          <idle>-0       (-------) [003] dn.1   345.099265: irq_handler_entry: irq=1 name=IPI
          <idle>-0       (-------) [003] dn.1   345.099266: ipi_entry: (Rescheduling interrupts)
          <idle>-0       (-------) [003] dN.1   345.099268: ipi_exit: (Rescheduling interrupts)
          <idle>-0       (-------) [003] dN.1   345.099270: irq_handler_exit: irq=1 ret=handled
          <idle>-0       (-------) [003] d..2   345.099284: sched_switch: prev_comm=swapper/3 prev_pid=0 prev_prio=120 prev_state=R ==> next_comm=VizCompositor next_pid=9171 next_prio=116
          <idle>-0       (-------) [001] dnh6   345.099290: sched_waking: comm=TimerDispatch pid=s prio=97 target_cpu=001
Chrome_ChildIOT 8871-8871    (   8471) [000] d..2   345.099306: sched_waking: comm=uhk_traffic pid=8954 prio=120 target_cpu=002
          <idle>-0       (-------) [001] dnh7   345.099317: ipi_raise: target_mask=00000000,00000004 (Rescheduling interrupts)
          <idle>-0       (-------) [001] dnh7   345.099321: sched_wakeup: comm=TimerDispatch pid=w prio=97 target_cpu=002
          <idle>-0       (-------) [002] dn.1   345.099321: cpu_idle: state=4294967295 cpu_id=2
          <idle>-0       (-------) [002] dn.1   345.099325: irq_handler_entry: irq=1 name=IPI
          <idle>-0       (-------) [002] dn.1   345.099327: ipi_entry: (Rescheduling interrupts)
          <idle>-0       (-------) [002] dN.1   345.099328: ipi_exit: (Rescheduling interrupts)
          <idle>-0       (-------) [002] dN.1   345.099329: irq_handler_exit: irq=1 ret=handled
Chrome_ChildIOT 8871-8871    (   8471) [000] d..3   345.099330: sched_wakeup: comm=uhk_traffic pid=8954 prio=120 target_cpu=002
          <idle>-0       (-------) [001] dnh1   345.099334: irq_handler_exit: irq=11 ret=handled
Chrome_ChildIOT 8871-8871    (   8471) [000] d..2   345.099336: sched_waking: comm=VizCompositor pid=9171 prio=116 target_cpu=003
          <idle>-0       (-------) [002] d..2   345.099339: sched_switch: prev_comm=swapper/2 prev_pid=0 prev_prio=120 prev_state=R ==> next_comm=TimerDispatch next_pid=2689 next_prio=97
          <idle>-0       (-------) [001] dnH1   345.099347: irq_handler_entry: irq=211 name=kgsl_3d0_irq
          <idle>-0       (-------) [001] dnH4   345.099363: sched_waking: comm=kgsl_dispatcher pid=962 prio=49 target_cpu=002
          

往前一次唤醒vsync-sf 关系

GPU completion 13438-13438   (   7730) [002] d..2   345.090390: sched_switch: prev_comm=GPU completion prev_pid=13438 prev_prio=110 prev_state=S ==> next_comm=swapper/2 next_pid=0 next_prio=120
          <idle>-0       (-------) [002] d..1   345.090410: cpu_idle: state=0 cpu_id=2
          <idle>-0       (-------) [001] d..1   345.090413: cpu_idle: state=4294967295 cpu_id=1
          <idle>-0       (-------) [001] d.h1   345.090420: irq_handler_entry: irq=11 name=arch_timer
          <idle>-0       (-------) [001] d.h6   345.090427: sched_waking: comm=TimerDispatch pid=2689 prio=97 target_cpu=001
    <idle>-0       (-------) [001] dNh7   345.090447: sched_wakeup: comm=TimerDispatch pid=2689 prio=97 target_cpu=001
    <idle>-0       (-------) [001] d..2   345.090470: sched_switch: prev_comm=swapper/1 prev_pid=0 prev_prio=120 prev_state=R ==> next_comm=TimerDispatch next_pid=2689 next_prio=97

1、跟显示关系

2、vsync-app   不稳定，是由于epoll  SF 中 fd 时，由于设置的timer 时间到了，而写fd 内容延迟，导致epoll 延迟从而vsync 不稳定；是由于定时器定制内容导致定时器中断执行耗时。

定时器中断

https://www.cnblogs.com/hellokitty2/p/15666357.html

定时器中断执行约2.5ms ，导致vsync-app 过长。

binder:5035_3-5052    (   5035) [000] d.h. 11255.656009: irq_handler_entry: irq=11 name=arch_timer

binder:5035_3-5052    (   5035) [000] d.h5 11255.658528: sched_waking: comm=TimerDispatch pid=2091 prio=97 target_cpu=000

binder:5035_3-5052    (   5035) [000] d.h6 11255.658568: sched_wakeup: comm=TimerDispatch pid=2091 prio=97 target_cpu=003

<idle>-0       (-------) [003] d..2 11255.658592: sched_switch: prev_comm=swapper/3 prev_pid=0 prev_prio=120 prev_state=R ==> next_comm=TimerDispatch next_pid=2091 next_prio=97

binder:5035_3-5052    (   5035) [000] d.h. 11255.658574: irq_handler_exit: irq=11 ret=handled

打开更多的trace 开关 

adb shell "echo 1 > sys/kernel/tracing/events/irq/enable"
adb shell "echo 1 > sys/kernel/tracing/events/timer/enable"
adb shell "echo 1 > /sys/kernel/tracing/events/preemptirq/irq_disable/enable"
adb shell "echo 1 > /sys/kernel/tracing/events/preemptirq/irq_enable/enable"
adb shell "echo 1 > /sys/kernel/tracing/events/preemptirq_long/irq_disable_long/enable"
adb shell "echo 1 > /sys/kernel/tracing/events/preemptirq_long/preempt_disable_long/enable"
adb shell "echo 1000000 > /proc/sys/preemptirq/irqsoff_tracing_threshold_ns"
adb shell "echo 1000000 > /proc/sys/preemptirq/preemptoff_tracing_threshold_ns"

慢滑

while true; do

adb shell input swipe 570 1800 570 400 4000

adb shell input swipe 570 400 570 1800 4000

((count++))

echo "We have swipe $count times !"

done

3、cpu 进入C3 状态，timer 中断执行时，退出C3 状态耗时。

怎么确定唤醒关系从trace 里面看是否可信,抓下kernel stack

echo stacktrace > /sys/kernel/tracing/events/sched/sched_wakeup/trigger echo stacktrace > /sys/kernel/tracing/events/sched/sched_waking/trigger

core_ctl关核策略isolate、pause/resume比较耗时，halt

定时器不准可能跟pause/resume时间有关

可以用下面命令验证一下

取消core_ctl关核

echo 1 > /sys/devices/system/cpu/cpu7/core_ctl/min_cpus

echo 3 > /sys/devices/system/cpu/cpu4/core_ctl/min_cpus

关掉idle

echo 1 > /sys/devices/system/cpu/qcom_lpm/parameters/sleep_disabled

vsync 文档：

https://download.csdn.net/download/lei7143/87759603

丢帧情况

性能问题分析systrace要点 - 知乎

性能问题分析systrace要点 - 知乎 (zhihu.com)

fence

Android 图像显示系统 - 开篇_android fence-CSDN博客

[070]一文带你看懂Vsync Phase-腾讯云开发者社区-腾讯云

SF.commit & SF.composite

https://blog.csdn.net/duohen/article/details/126750868