移动性能测试 介绍下基于 systrace gfx 统计帧率方案的实现过程

浮云 · 2019年10月24日 · 最后由 testly 回复于 2024年03月08日 · 5046 次阅读

前述

完成方案后开源了,也没见有反馈的,今天公司内部做了分享,在此也把实现过程分享下。

设想过程

一、起始需求:解决如何持续抓取 systrace

Step1:了解 sysrrace 背景,依靠搜索

  • Android 的 systrace 怎么抓取的?: 使用 atrace
  • Systace 的 log 写在哪?:/sys/kernel/debug/tracing/trace_pipe

Step2:如何解决持续抓取?

  • atrace gfx -b 1024 -c --async_start(1M buffer 持续输出 gfx 的 trace 信息)
  • adb shell cat /sys/kernel/debug/tracing/trace_pipe (持续抓取)
  • atrace gfx --async_stop(停止 gfx 的 systrace 的记录)

二、既然拿到了每一帧的绘制过程,能不能用来统计帧率?

Step1:首先的了解下 SurfaceFlinger 的绘制过程:VSYNC on Android N

  • 关注到几个关键函数:setUpHWComposer、postFramebuffer、postComposition
    • 决定用 postFramebuffer 判断之后一个 vsync 是不是真的绘制了画面
  • 拿到了绘制时间点,怎么判定这帧内容归属,分析下 systrace 格式:
DispSync-799    (  683) [000] ...1 1080841.601945: tracing_mark_write: C | 683 | VSYNC-app|1
DispSync-799    (  683) [000] ...1 1080841.602019: tracing_mark_write: C | 683 | VSYNC-sf|1
<...>-683       (-----) [000] ...1 1080841.602840: tracing_mark_write: C | 683 | StatusBar#0|1
<...>-683       (-----) [001] ...1 1080841.605342: tracing_mark_write: B | 683 | postFramebuffer
DispSync-799    (  683) [000] ...1 1080841.618617: tracing_mark_write: C | 683 | VSYNC-app|0
DispSync-799    (  683) [000] ...1 1080841.618664: tracing_mark_write: C | 683 | VSYNC-sf|0
    • 有 B、E、C,起始、结束、完成
    • “|” 分割有三列和四列的情况,四列的全是 C,第三列是函数

Step2:处理逻辑:

  • 只要有 postFramebuffer 统计这帧信息
  • .两个 vsync 之间 C 最后完成的作为这一帧的归属
  • C 的数据中提取包名和 activity,未产生新的变化则沿用
  • 调试中发现有一类 TX - 信息出现在 app 运行、退出、局部 surface 内容变化,提出来单独记录

Step3:帧率统计逻辑

  • 数组统计
  • Index 格式:TX,app,SV(是否包含 TX,包名,绘制内容 surface 名)
  • 记录的数据:
    • 帧数 N[index]
    • 时间累加 Time[index]
    • 起始时间 b[index]
    • 结束时间最近一个 vsync 时间 V[index]
    • 最大卡顿 M[index]
    • 大于 500ms 为等待不参与帧率评估,等待时间 StopT[index]、次数 Stop[index]
    • 卡顿程度体验区间 A~C,超过 vsync 间隔的绘制性能掉帧 D
  • 流畅度加权评价:满足基础帧率程度 60%、最大卡顿相对于体验要求的程度 20%、卡顿比例 20%
  • 单帧卡顿详细信息,按需配置是否输出,把单帧 C 部分信息输出

三、结果 csv 由 PC 端处理生成报告

实现脚本细节

一、监控脚本

  • 设备端后台脚本:不受 Android 管理,只怕父进程退出 adbd
  • 依赖 busybox,push 到手机使用:
    • adb push busybox /data/local/tmp
    • adb shell chmod 755 /data/local/tmp/busybox
  • 文本流实时处理依赖 awk 的逻辑设计,下面详细注解了下脚本逻辑
“注:”部分是解释影响脚本执行,此文件是代码细节介绍

注:shell脚本指定执行的工具位置,也可以不指定执行命令调用
#!/system/bin/sh

注:判定依赖的busybox是否存在,存在则赋予bb全局变量方便使用
if [ -f /data/local/tmp/busybox ];then
    bb="/data/local/tmp/busybox"
else
    echo "No /data/local/tmp/busybox"
    exit
fi

注:按一般命令工具方式设计,help文本
show_help() {
echo "
Usage: sh gfx.sh [ -t target_FPS ] [ -k KPI ] [ -T output_type ] [ -d delay_time ] [ -f output_frames ] [ -F output_folder ] [ -h ]

POSIX options | GNU long options

    -t   | --target         The target FPS. Default: 60
    -k   | --KPI            The one frame's kpi time for scoring. Default: 100ms
    -T   | --type           The output type [0~4]. Default: 0
    -d   | --delay          The delay time for checking output. Default: 1 (S)
    -f   | --frames         The frames number to output resulr. Default: 20
    -F   | --folder         The folder name for resulr csvs(/data/local/tmp/). Default: fps
    -h   | --help           Display this help and exit
"
}

注:全局变量指定默认值
注:目标帧率,用于加权评价
target=60
注:目标卡顿评估线,生物概念认知:人眼有100ms buffer,100ms以上判定为卡顿,一些视觉敏感的人或经过训练的人识别卡段的能力会提高
KPI=100
注:输出类型0到4,0——只输出帧率统计;1——增加体验认知卡顿的单帧信息;2——大于vsync的卡顿帧信息输出;3——只输出1中的卡顿信息;4只输出2中的卡顿信息
type=0
注:查询是否输出帧率统计的间隔,单位秒,控制输出文本量
delay=1
注:控制帧率计算的1起步总帧数,默认大于20帧输出
frames=20
注:测试结果文件夹名,默认fps,在/data/local/tmp/下,此目录用户不可见,常用于脚本执行
folder=fps

注:模拟命令行工具传入参数的解析,shift是逐个参数右移删除
while :
do
    case $1 in
        -h | --help)
            show_help
            exit 0
            ;;
        -t | --target)
            shift
            target=$1
            shift
            ;;
        -T | --type)
            shift
            type="$1"
            shift
            ;;
        -k | --KPI)
            shift
            KPI=$1
            shift
            ;;
        -d | --delay)
            shift
            delay="$1"
            shift
            ;;
        -f | --frames)
            shift
            frames="$1"
            shift
            ;;
        -F | --folder)
            shift
            folder="$1"
            shift
            ;;
        --) # End of all options
            shift
            break
            ;;
        *)  # no more options. Stop while loop
            break
            ;;  
    esac
done

注:解析功能独立函数设计,以便其他脚本复用
#参数说明
## $1 = 目标帧率
## $2 = 评估体验卡顿的把控线
## $3 = 输出类型:
##      0) ~ 默认只输出帧率
##      1)~ 增加APP内容两帧间隔 >42ms 的单帧信息
##      2)~ 增加绘制间隔 >vsync间隔的单帧信息
##      3)~ 只输出APP内容两帧间隔 >42ms 的单帧信息
##      4)~ 只输出绘制间隔 >vsync间隔的单帧信息
## $4 = 检查输出结果的间隔
## $5 = 检查输出时,满足?帧以上输出条件的才输出
GFX(){
#如果systrace打开则关闭
if [ `cat /sys/kernel/debug/tracing/tracing_on` -eq 1 ];then
    echo "atrace gfx stop"
    atrace gfx --async_stop 1>/dev/null &
    $bb sleep 3
    kill $!
fi
#vsync 间隔获取
local sync=`dumpsys SurfaceFlinger --latency|$bb awk 'NR==1{r=$1/1000000;if(r<0)r=$1/1000;print r}'`
#当前选中的activity
local hasFocus=`dumpsys input|grep "hasFocus=true"|$bb awk '{print substr($4,1,length($4)-3)}'`
#提取当前显示activity的app
local app=`echo $hasFocus|$bb awk -F "/" '{print $1}'`
#开始输出systrace log: 1M 循环buffer 的gfx信息
echo "atrace gfx -b 1024 -c --async_start"
atrace gfx -b 1024 -c --async_start

#awk解析
注:-F 指定间隔符,这里是 |
$bb awk -F "|" \
注:外部变量传入
-v sync="$sync" \
-v OFS=, \
-v app="$app" \
-v activity="$hasFocus" \
-v target="$1" \
-v kpi="$2" \
-v type="$3" \
-v delay="$4" \
-v fames="$5" \
-v csv=$monitor/fps.csv \
-v csv1=$monitor/dropFrames.csv \
注:awk有三部分BEGIN{}{}END{},BEGIN是第一行之前的处理,END是最后一行之后。可以在BEGIN中将传入变量做进一步的处理
注:这里的实现是因为要在退出时把未输出的数据输出,在awk内部做的逐行读取处理,所以只有BEGIN;对于awk外部命令调用不支持的有gfx_no_system.sh
注:awk是单行执行或传入脚本文件,这里为了方便看在每行后加的“ \” 只代表每一行是连接的非换行,为了方便看去掉awk首尾单引号
    BEGIN{ \
        注:while("cat /sys/kernel/debug/tracing/trace_pipe"|getline){} 是awk的调用外部命令的逐行处理,getline是获取行能容函数,这么做的目的是kill掉cat进程后可以继续输出数组中的数据
        while("cat /sys/kernel/debug/tracing/trace_pipe"|getline){ \
            注:只处理四列的C和postFramebuffer所在行信息
            if(NF==4||$3=="postFramebuffer"){ \
                注:第三列是VSYNC的进行统计处理。VSYNC-sf和VSYNC-app是android P之后的,之前是VSYNC-sf-app未区分
                if($3~/VSYNC-sf|VSYNC-app|VSYNC-sf-app/){ \
                    注:gsub是替换函数支持正则(目标字符串,替换为字符串,处理的字符串变量),多用于格式混乱不好处理的内容进行初步格式化
                    gsub(/.*.) |: tracing_mark_write: C/,"",$1); \
                    注:将替换后的字符串切割为函数,目的是提取时间的字符串,T[3]是需要的时间,shell的数组是从1起,并不是0
                    split($1,T," "); \
                    注:起始时间变量f,用于计算输出间隔处理输出判定。awk的变量无需初始化,默认空,变量转换也随意,字符串+0=0,a[1]=0, a就是数组,delete a直接删除
                    if(f==""){ \
                        f=T[3]; \
                        注:根于type的值判定输出状态logF是统计帧率对应fps.csv,logD是卡顿掉帧对应dropFrames.csv
                        logF=1; \
                        logD=0; \
                        if(type==1){ \
                            logD=1 \
                        }else{ \
                            if(type==2){ \
                                logD=2; \
                            }else{ \
                                if(type==3){ \
                                    logF=0; \
                                    logD=1 \
                                }else{ \
                                    if(type==4){ \
                                        logF=0; \
                                        logD=2 \
                                    } \
                                } \
                            } \
                        } \
                    }else{ \
                        注:post代表最近一个vsync间隔内是否包含postFramebuffer,awk是逐行处理上下文的判定需要个状态变量
                        if(post==1){ \
                            注:处理index(p)的surface名部分,即帧内容的归属,同样是之前行处理是传递下来的变量值
                            if(sv!=""){ \
                                SV=sv \
                            }else{ \
                                SV=activity \
                            }; \
                            p=TX","app",\""SV"\""; \
                            注:判定绘制间隔,超过则 D[p]+=1
                            t=(T[3]-VSYNC)*1000; \
                            if(t>sync){ \
                                d=1 \
                            }else{ \
                                d=0 \
                            }; \
                            注:计算体验卡顿,即相同窗口前后两帧的时间差
                            wt=(T[3]-V[p])*1000; \
                            注:只对间隔<500ms的数据进行帧率统计,大于的记录等待,从而可以提高帧率统计值的意义,避免等待影响帧率波动
                            if(wt<500){ \
                                注:掉帧卡顿的输出处理
                                if(d==1){ \
                                    if(logD==2){ \
                                        print VSYNC,T[3],t,$3,p,"\""info"\"">csv1 \
                                    }else{ \
                                        if(logD==1){ \
                                            if(wt>=42)print V[p],T[3],wt,$3,p,"\""info"\"">csv1 \
                                        } \
                                    } \
                                }; \
                                注:帧率统计所需数组的记录,舍弃了≥500ms的
                                if(logF==1){ \
                                    注:帧数
                                    N[p]=N[p]+1; \
                                    注:耗时总计
                                    Time[p]=Time[p]+wt; \
                                    注:最大卡顿
                                    if(M[p]==""){ \
                                        M[p]=wt \
                                    }else{ \
                                        if(M[p]<wt)M[p]=wt \
                                    }; \
                                    注:[100,500) 卡顿区间,基于人眼的100ms buffer
                                    if(wt>=100){ \
                                        A[p]=A[p]+1 \
                                    }else{ \
                                        注:[50,100) 卡顿区间,20帧是游戏卡顿可玩忍受底线,再低就是卡片交互类游戏了,不是即时交互类游戏
                                        if(wt>=50){ \
                                            B[p]=B[p]+1 \
                                        }else{ \
                                            注:[42,50) 卡顿区间,电影24帧录制,网络视频25帧播放,视频体验延迟区间
                                            if(wt>=42)C[p]=C[p]+1 \
                                        } \
                                    } \
                                } \
                            }else{ \
                                注:记录等待的时间和次数
                                if(logF==1&&b[p]!=""){ \
                                    Stop[p]=Stop[p]+1; \
                                    StopT[p]=StopT[p]+wt \
                                } \
                            }; \
                            if(logF==1){ \
                                注:超过vsync间隔的掉帧记录,绘制性能问题,需减小绘制buffer或优化绘制的framework层面优化
                                if(d==1)D[p]=D[p]+1; \
                                注:更新index的起始时间
                                if(b[p]=="")b[p]=T[3]; \
                                V[p]=T[3]; \
                                注:判定检查间隔
                                if(T[3]-f>=delay){ \
                                    注:判定帧数据数据间隔,有窗口帧率数据则处理
                                    if(length(N)>0){ \
                                        注:数组的逐个处理
                                        for(i in N){ \
                                            注:帧数大于配置的帧数则输出,如默认的20帧
                                            if(N[i]>fames){ \
                                                注:计算帧率
                                                fps=sprintf("%.1f",N[i]*1000/Time[i]); \
                                                注:处理小数点精度,避免歧义,因为vsync间有微秒级别浮动
                                                if(fps>=target){ \
                                                    fps=int(fps); \
                                                    g=1 \
                                                }else{ \
                                                    g=fps/target \
                                                }; \
                                                if(kpi<M[i])h=kpi/M[i];else h=1; \
                                                注:流畅度加权计算评估
                                                ss=sprintf("%.2f",g*60+h*20+(1-A[i]/N[i])*10+(1-B[i]/N[i])*7+(1-C[i]/N[i])*3); \
                                                print b[i],V[i],fps+0,N[i],sprintf("%.3f",Time[i]/1000)+0,M[i],sprintf("%.3f",StopT[i]/1000)+0,Stop[i]+0,A[i]+0,B[i]+0,C[i]+0,D[i]+0,ss+0,i>>csv; \
                                                注:对输出的数据进行初始化,下一轮统计
                                                b[i]=V[i]; \
                                                N[i]=""; \
                                                Time[i]=""; \
                                                M[i]=""; \
                                                StopT[i]=""; \
                                                Stop[i]=""; \
                                                A[i]=""; \
                                                B[i]=""; \
                                                C[i]=""; \
                                                D[i]="" \
                                            } \
                                        } \
                                    }; \
                                    注:更新判定间隔的起始时间
                                    f=T[3]; \
                                } \
                            } \
                        };
                    }; \
                    注:记录最近一个VSYNC时间
                    VSYNC=T[3];     
                    注:state、TX,post,sv,info,处理状态用于上下文判定,经过vsync的判定处理为1
                    state=1; \
                    TX=0; \
                    post=0; \
                    sv=""; \
                    info="" \
                }else{ \
                    注:更新:state、TX,post,sv,info的内容为了vsync行处理时所用,就是上线文间靠变量实现内容信息的传递
                    if(NF==3){  \
                        state=0; \
                        post=1 \
                    }else{ \
                        if(state==1&&$3!~/HW_VSYNC_ON_0|HW_VSYNC_0|hasClientComposition|FrameMissed|FramebufferSurface/){ \
                            if(logD>0){ \
                                if(info="")info=$3;else info=info"\n"$3 \
                            }; \
                            if($3~/TX - /){ \
                                TX=1 \
                            }else{ \
                                注:提取更新app包名和activity名
                                l=split($3,Check,"."); \
                                if(l>2){ \
                                    l=split($3,tmp,"/"); \
                                    if(l>1){ \
                                        sv=$3; \
                                        l=split($3,Check," "); \
                                        if(l==1){ \
                                            app=tmp[1]; \
                                            activity=$3 \
                                        } \
                                    }else{ \
                                        sv=$3 \
                                    } \
                                }else{ \
                                    sv=$3 \
                                } \
                            } \
                        } \
                    } \
                } \
            } \
        }; \
        注:kill掉cat /sys/kernel/debug/tracing/trace_pipe进程后开始执行,把未输出的数组数据进行输出,避免丢弃,不支持system()调用的设备在结束时只好丢掉了这部分数据gfx_no_system.sh
        if(length(N)>0){ \
            for(i in N){ \
                if(N[i]>0){ \
                    fps=sprintf("%.1f",N[i]*1000/Time[i]); \
                    if(fps>=target){ \
                        fps=int(fps); \
                        g=1 \
                    }else{ \
                        g=fps/target \
                    }; \
                    if(kpi<M[i])h=kpi/M[i];else h=1; \
                    ss=sprintf("%.2f",g*60+h*20+(1-A[i]/N[i])*10+(1-B[i]/N[i])*7+(1-C[i]/N[i])*3); \
                    print b[i],V[i],fps+0,N[i],sprintf("%.3f",Time[i]/1000)+0,M[i],sprintf("%.3f",StopT[i]/1000)+0,Stop[i]+0,A[i]+0,B[i]+0,C[i]+0,D[i]+0,ss+0,i>>csv \
                } \
            } \
        } \
    } & 注:&是后台进程执行,用于离线脱机,不阻塞执行

注:输出cat /sys/kernel/debug/tracing/trace_pipe的pid,停止是可直接kill此进程
#获取cat进程pid
local catPid=`$bb ps|$bb awk '$4=="cat"&&$5=="/sys/kernel/debug/tracing/trace_pipe"{print $1}'`
echo "cat Pid="$catPid
#等待 cat /sys/kernel/debug/tracing/trace_pipe进程退出,后子进程退出
注:等待子进程退出命令,wait,和位置相关,这里只等待函数内起的子进程
wait
#停止systrace
if [ `cat /sys/kernel/debug/tracing/tracing_on` -eq 1 ];then
    echo "finish: atrace gfx stop"
    atrace gfx --async_stop 1>/dev/null &
    $bb sleep 3
    kill $!
fi
}

#main
${testresult="/data/local/tmp/"} 2>/dev/null
monitor="$testresult/$folder"
if [ -d $monitor ];then
    $bb rm -r $monitor
fi
mkdir -p $monitor
if [ $type -lt 3 ];then
    echo "start time,end time,FPS,frames,Time(S),max time(ms),waiting time(S),wait times,A,B,C,D,score,TX,app,Surface" >$monitor/fps.csv
fi
if [ $type -gt 0 ];then
    echo "start VSYNC,end VSYNC,used time(ms),VSYNC type,TX,app,Surface,info" >$monitor/dropFrames.csv
fi

注:函数的调用,函数话设计就是可按需集成到其他脚本的需求中
GFX $target $KPI $type $delay $fames

二、报告生成

  • 方案用了 python pandas 库处理 csv 数据
  • 报告用 html + js + css 的方式设计
  • 报告数据文件用直接生成 js 文件引入报告使用,动态加载 js 文件更新数据,所以这里浏览器需要支持本地 js 文件读取权限,打开权限方式此开源项目有说明,就不再写一遍了
  • 除了更新数据的模板维护 GFX_HTML 中,web 基础可看源码
  • 此形式的报告支持本地浏览器查看、和服务器端地址查看(不需要本地读取 js 权限)

项目开源地址:(https://github.com/sandmanli/android_FPS_frome_GFX)

如果觉得我的文章对您有用,请随意打赏。您的支持将鼓励我继续创作!
共收到 14 条回复 时间 点赞

今天看到一份监控结果中 SurfaceTexture 很多名字挂了数字,如"SurfaceTexture-0-1980-2",统一做了下归类处理,全部重名名为 SurfaceTexture。对应脚本有更新。

此方案确实可以把一类特殊场景绘制部分数据分出来,这里说的场景是这样的:
1、背景有个动效始终循环绘制,哪怕被其他页面覆盖,可以用开发者模式的 GPU 呈现模式分析查看,画面静止但有数据绘制;
2、实际显示页面间隔绘制内容
3、此方案就可以取到绘制的内容,而非不显示的 buffer 绘制

用基于 SurfaceFlinger --latency 的方案就做不到,因为抓取了未显示部分的 buffer 绘制,影响了实际显示内容帧率的评估。

浮云 Android FPS 方法探讨 中提及了此贴 10月29日 23:54
匿名 #4 · 2019年12月16日

我想请问下大佬,这个能计算出视频全屏播放 + 弹幕的卡顿吗,我现在用 dumpsys 。。。--latency 那个命令,在播放腾讯/爱奇艺在线视频的时候,获取不到数据,可以把卡顿定义为>16.7ms 这样吗。另外小白想知道可以在 window 下用吗,感觉问的问题好初级,希望大佬不要介意,我没用过 shell 脚本😂

dumpsys SurfaceFlinger --latency 可以的,应该是窗口名没配置正确。看下https://testerhome.com/topics/20187
PC 端不分 rom,windows、os、ubuntu 都可以,shell 脚本是在安卓端执行的,adb 命令执行、

匿名 #6 · 2019年12月16日
浮云 回复

😭 很奇怪,我把每个窗口都试了一遍都没有数据,即使有也是那种好久没有刷新的数据,优酷/bilibili 是可以的。我是用这个 adb shell dumpsys SurfaceFlinger 命令获取窗口的

明确下安卓版本,android7.1 之后名字有改,如果有 surfaceview - 包名 #0 这种需要加双引号,因为有空格。

匿名 · #8 · 2019年12月20日
仅楼主可见
匿名 · #9 · 2019年12月23日
仅楼主可见

同名多窗口数据在一起,你取下 dumpsys SurfaceFlinger --latency SurfaceView 就能看到,两组数据空格间隔,我的监控脚本中 WN 列会记录从 1 开始

想问下楼主在测试聊天界面滑动的时候获取平均帧率数据较低,可能是存在什么问题?

浮云 #12 · 2020年10月10日 Author
亦难亦安 回复

滑动的效果有起始、滑动中、滑动结束后的减速效果,而且还跟滑动动作速度有关。要看评估哪段区间。整体帧率会被起始、结束和操作动作影响。

浮云 回复

评估滑动中的帧率,滑动一次,记录一次帧率,统计上下滑动各两次帧率数据就普遍偏低。不知道还有没有什么方式😂 还有,用红米 K30 跑出来帧刷新率都在 30HZ,系统设置的 60HZ

浮云 #14 · 2020年10月12日 Author
亦难亦安 回复

手机 rom 测试的话,分滑动场景,持续滑动取连续滑动期间的帧率,测性能的机械臂也是一样的方式。

兄弟,加个 vx,有问题交流下?vx:13262561732

需要 登录 后方可回复, 如果你还没有账号请点击这里 注册