智慧 + 毅力 = 无所不能

正确性、健壮性、可靠性、效率、易用性、可读性、可复用性、兼容性、可移植性...

导航

UE高级性能剖析技术

Posted on 2020-07-15 14:18  Bill Yuan  阅读(1745)  评论(0编辑  收藏  举报

https://blog.csdn.net/leonwei/article/details/95527109

在最前面

基于UE的手游客户端的性能主要由这七大部分构成:CPU逻辑,CPU渲染,图形API(提交),GPU渲染,内存,带宽,加载时间。这几个基本元素又会合力衍生出一些新的性能指标,例如功耗(往往同gpu负载和带宽紧密相关)。同时这七部分又构成一个闭合的木桶,最长的一块是主要瓶颈,并且瓶颈可以在这几块转移流动。作为开发者我们解决性能问题的步骤一般都是按照做性能剖析,解读结果,定位问题,增加剖析代码,优化问题,重复剖析的迭代过程来执行。而高效准确详细的对性能进行剖析得到结果是第一步,在任何引擎上,只要我们能做到在任意时刻准确的获取想要的性能剖析结果,那么才会胸有成竹不会慌,该系列文章将归纳总结在ue下对每一性能指标的剖析方法,做深入分析,我们需要工具的帮助,也需要程序员理解引擎并知道如何去编写合适的剖析代码。

 

最近刚好做过一轮RHI线程的剖析,第一篇就从RHI开始,我会坚持把后面几篇写下去。

渲染API瓶颈

渲染API瓶颈是3D手游的常见瓶颈,我们常说的drawcall 过多了,卡渲染就是指的卡在这里,其实这个卡渲染卡的是cpu。为什么drawcall会卡,因为cpu需要通过对渲染api的调用来驱动gpu做事情,1个drawcall的背后是一堆渲染api的调用,下面是一个常见的drawcall过程,

 

可以看到为了一次绘制(1个drawcall),要设置shader,创建buffer等等,这些相比最后的draw那一步来说都是相对更费时的。

当测试反馈给我们卡drawcall的时候,作为程序我们需要一种手段来衡量出确切的当前做哪些drawcall,或者说绘制哪些东西更耗,最好是精确到耗在绘制哪个模型的哪个api调用上,我们才能真正的给美术予以优化指导。

UE中精确定位RHI瓶颈

在UE中,pc和android平台通常渲染api的调用会放在一个单独的线程,叫做RHI线程,这个线程专门负责渲染指令的提交,即调用显卡的API。我们分析渲染提交的卡顿就是要分析这个RHI线程。

多线程渲染工作模型

但是RHI线程不是单独存在的,它需要同game,render线程协作,rhi的卡顿可能不只是rhi的卡顿,首先需要清楚UE里面RHI线程和其他线程的工作模式:

 

 

这里面game render rhi gpu分别在4个并行的工作线上,有这样几个特点:

game thread最多可以等渲染一帧,也就是说渲染如果第N帧的渲染在第N+1帧的game tick结束时还没有完成,那么渲染就会把game卡住,render 和rhi不会有帧延迟。
game是render和rhi的源驱动者,game的卡顿可能会卡住渲染
render 负责产生drawcall,rhi负责提交drawcall,因此render的卡顿也可能卡住rhi提交。
渲染的最后一步要swapbuffer,即等待gpu完成,所以gpu的卡顿也可能会卡住rhi。
除了gamethread本身,render  rhi 和gpu的工作都是存在间隙的,即game逻辑喂给渲染任务的时机会影响渲染工作的密度,也会影响到渲染的时间,小量多次会浪费渲染效率。
 

UE中rhi的瓶颈的来源

现在我们知道rhi的卡顿可能来自于以下几种情况:

a RHI指令自身的卡顿,即通常所说的卡drawcall,过多的dc,过多的渲染状态切换,过多的渲染资源创建,等等;

b game或者render thread的卡顿

c gpu的卡顿。

 

对于情况b,我们可以通过UE的status 看当前的game和render的线程执行时间来容易的判断出来,来排除是rhi上出了问题。

对于情况c, UE的status中在rhi线程上会统计一个叫做swapbuffer的时间,如果这个时间过长,那么就是gpu瓶颈了。

 

真正比较麻烦的是定位情况a,即对于rhi指令本身的卡顿瓶颈。对于这种情况UE自带的stat工具通常不能给出比较有力的分析结果,自带的方法只能统计一帧在rhi上做几种给定操作的时间,但是在复杂的线程条件下,有时很难确定这些卡顿的幕后原因,有时rhi问题只是一个表象,为了得到rhi线程瓶颈的确切原因,我们至少要能够明确以下几个事情:

 

1 Rhi线程的执行是由一堆有序的rhi command组成的,我们要能捕捉到具体的那一个rhi command的执行时间比较长,比如是创建场景中哪个房子的vb?

2 是在render thread的哪一个步骤塞入的渲染数据导致了这个rhi command执行的时间比较长,是在渲染阴影的时候,还是渲染basepass,还是做遮挡剔除?

3 是在game thread的哪一个步骤塞入的渲染数据导致了这个rhi command执行的时间比较长?是在加载场景?还是在绘制UI的时候?

 

笔者在项目中遇到过一个问题,在一些低端机,rhi会有时突然卡顿几秒以上,看stat文件如下:

 

我只能看到在rhi 线程的thcikbegin阶段发生了巨大的卡顿,然后就没有细节了,不知道是具体哪个rhicommand,然后看gamethread在wait,也不知道是game thread的哪一步触发了这个rhi瓶颈。我们需要一些办法。

 

定位UE中rhi线程的瓶颈

我们需要分别将上面三种原因捕捉到,就能解开这个问题。

首先定义一个宏,只有我们需要捕捉这些详细的rhi瓶颈时开启,因为这些操作会存在较大的overhead。

 

定位具体rhicommand的时间

对于rhi command的具体执行时间,我在FRHICommand的最终执行阶段ExecuteAndDestruct中创建一个FScopeCycleCounter,counter的名字就直接rtti当前command的typename。

有时候我们需要更细节的知道这个command除了类型外的信息,例如如果这是一个createvb的command,那么vb的原始模型名字是什么,vb大小等,我在一些command处额外传了一些debug用的string,然后在这些command的执行前补上一个FScopeCycleCounter。这样我们就能拿到精确到具体rhicommand的提交耗时了。经过这个补充,我能拿到这样的rhi 线程执行时间统计:

 

这样谜底就清晰了很多,原来这时候存在大量的vb创建,数了一下,有几百个,在同一帧内几百个vb的创建,在低端android上会产生5秒钟的超级卡顿,那么问题来了,为何在这一帧会同时产生这么多的vb卡顿,是game或者render 上发生了什么事情,如果我们查看当前的game thread ,它显示的是wait,是不知道原因的,因为game ,render ,rhi是分开工作的,我们现在rhi处于瓶颈已经不是事故的”第一现场”了,我们需要进一步让你发生在第一现场。

定位在render的哪个阶段发生了rhi的瓶颈

UE的rhicommandlist自带了一个函数FRHICommandListImmediate::SetCurrentStat,可以用来让render给rhi加一个标记,这个标记就可以认为是render的某个阶段的名字,UE自带了在render 的很多阶段下了这个标记,我们还可以自己补充,这个函数的原理如下:

 

这个status本身也是以command的形式插入队列,所以每一条rhi执行的cmd会被统计到它之前最近的那个status tag下面,通过不断的细分插入这些tag,我们可以跟踪到rhi的cmd从是在render的哪个阶段被产生。需要注意的是这个tag只能在render thread里插入。我为render thread补充了一些细化的tag后,如前面的图,我发现这个大量的vb创建发生在渲染线程的一帧渲染结束到下一帧渲染开始之前,在这个阶段有game 逻辑往render 里面堆入了大量创建vb的指令,所以问题还要继续往game thread 上找”第一现场”。

 

定位在Game的哪个阶段产生RHI瓶颈

其实我们仍然可以模仿renderthread一样在game thread上给rhi的command list里面插入tag,但是有个问题,renderthread是一种相对简单的render command的队列的顺序执行, tag量有限相对容易操作,但是game thread里面逻辑极其复杂,我们希望可以复用game thread上面已经埋好的一些scope counter,不过game和rhi是两条并行的thread,需要在我们关心的scope处让二者能够强行同步住,才能容易的使用game 自己的scope counter抓住rhi的执行。我们这样去实现,假设下面是我们关心的一个game thread的区段,在前后加上代码如下

#if STAT_RHI_ADVANCED

FlushRenderingCommands(true)

   DECLARE_SCOPE_CYCLE_COUNTER(TEXT("XXX "), STAT_XXX, STATGROUP_RHI_GAME_SYNC);

#endif

  //game 代码段
    …
    …
//

#if STAT_RHI_ ADVANCED

     FlushRenderingCommands(true);

#endif

 

FlushRenderingCommands(true)的意思是在这个位置强制将所有当前的rhicommand执行完毕,阻塞住当前线程,所以上面这个代码段的原有的XXX统计的时间将包括这段时间内因为game thread上发生的渲染事件的渲染而花费的时间。

 

通过在game thread的主要逻辑处,插入这些同步rhi线程的代码,当rhi线程发生瓶颈的时候,我们只要查看当前gamethread在哪里停住(wait event),就可以判断是什么game 逻辑导致了rhi线程的瓶颈。有了这个机制,我们接着截stat文件,会看到当rhi处于巨大瓶颈时,game thread停在了这里:

 

凶手被抓住了,是一个资源正在被缓存池预加载!

这个奇怪的rhi上的卡顿的真正原因其实是game 线程上在加载一个模型资源!如果只依靠ue本来的stat分析,是无论如何都不可能猜到这个幕后的凶手的。

 

那么问题来了,一个资源的加载为何会导致海量的vb同时创建?通过进一步的分析代码,会发现因为这里用的是同步加载,而UE的同步加载的机制,是创建一个加载任务堆到同异步加载一样的加载队列里,因为不能保证依赖关系,所以要等待当前所有队列中的任务完成才能继续下去,也就是说当前的同步加载的时间绝不仅仅是加载完你要的这个模型而已,他需要将当前异步加载任务在队列中的所有资源加载完!而这个时候恰恰处于场景在level streaming的阶段,最后发现此事加载队列中的资源上百个,这个同步加载遇上level streaming的结果就是,在这一帧要完成上百个模型的创建,模型的postload会初始化rhi资源,导致一帧内大量vb的创建,卡死rhi,所以罪魁祸首是同步加载,同步加载将level streaming的过程也强行同步了,找到了问题,我们就可以通过相关的优化手段来排除这个瓶颈。

 

RHI上的问题可能往往不只是rhi上的问题那么简单,通过上面说的一些方法我们可以清楚的看到各种rhi上瓶颈的真正原因。

CPU帧率瓶颈和卡顿

CPU上帧率低和卡顿是性能优化中最易出现的一部分,尤其对于手游,提到卡,就大概率是在CPU上出现的问题,CPU上的卡顿一般是卡逻辑或是卡渲染,本篇将详细系统的介绍基于UE的手游对CPU瓶颈的剖析方法。

低帧率和卡顿

首先低帧率和卡顿是两种完全不同的瓶颈类型,虽然归根到底都是某个函数执行的过慢引起的,但是定位和解决方法并不一样。低帧率瓶颈是需要统计一段时间内CPU把更多的时钟耗费在了哪些函数上,或统计一段时间内各个函数占用的cpu时间百分比,找到百分比高的将其优化,就会使帧率得到整体的提高。卡顿则是在一帧的一次运行内某段代码的运行产生了比平均情况明显的长时间,需要定义这段代码的起始点,分别进行计时,然后在连续的统计数据中找到峰值。简单来说帧率瓶颈是统计平均的CPU占用,而卡顿是找峰值。

 

         低帧率瓶颈—平均CPU占用

         对于UE程序,我们通常有下面一些方法去找到函数的平均CPU占用。一种是基于UE内置的stat机制,另一类是基于各种平台相关工具。

 

UE的stat机制:

UE自己的stat机制是一种基于埋点的机制,即通过在一段逻辑前后显示的增加标签来录得这段时间这个标签内逻辑的运行时间。然后利用ue的frontend可视化所有打了标签的函数的运行时间曲线。这个基于埋点的机制的好处是:不仅可以看到瓶颈cpu占用,也能看到峰值。缺点就是需要人工打标签,你需要不断的细分一些标签去找到瓶颈。详细的Stat参考文档包括

https://docs.unrealengine.com/en-US/Engine/Performance/StatCommands/index.html及https://docs.unrealengine.com/en-US/Engine/Performance/Profiler/index.html

 

Stat的代码机制是这样运作的:

首先ue有很多种类型的stat,测试cpu运行时间的stat叫做cycle stat。典型的使用分三步:

第一步:每个stat一定存在于一个stat group里,需要通过下面宏先定义一个stat group,

DECLARE_STAT_GROUP(Description, StatName, StatCategory, InDefaultEnable, InCompileTimeEnable, InSortByName)

这里的InDefaultEnable表示是否默认开启,默认不开启的话需要在运行时通过 stat group enable StatNamel来动态开启。这个宏会定义一个FStatGroup_StatName的结构体。

第二步:定义一个cycle stat,通过宏

DECLARE_CYCLE_STAT(CounterName,StatId,GroupId),这里的groupid就是之前定义的group的statname。这个宏其实是调用一个更加通用类型stat的声明 DECLARE_STAT(Description, StatName, GroupName, StatType, bShouldClearEveryFrame, bCycleStat, MemoryRegion),它会定义一个FStat__ StatId的结构体,并同时声明一个全局的FThreadSafeStaticStat<FStat__ StatId>变量StatPtr_StatId,这个变量有个主要的作用是高效率的通过getstatid()接口返回某个给定名字的statid的全局唯一的FStat__ StatId实例。

第三步:测量,定义好之后可以在一段代码的作用域开始处加入SCOPE_CYCLE_COUNTER(StatId),它会为当前作用域的前后埋点,这statid会用来统计这个作用域处的cpu时间开销,其实它获取到全局的这个FStat__StatId用其构造了一个FScopeCycleCounter的临时变量,它继承自FCycleCounter,它是个基于scope的变量,在构造的时候会调用FCycleCounter的start,start就会开始设定这个FStat__ StatId的统计,而析构的时候他调用FCycleCounter的stop来停止收集。

 

所谓收集的过程就是调用

FThreadStats::AddMessage( StatName, EStatOperation::CycleScopeStart ) 通知stat线程去进行一个给定名字的cycle事件的收集,结束则是调用的FThreadStats::AddMessage(StatId, EStatOperation::CycleScopeEnd)。FThreadStats::AddMessage是真正最终让UE做性能统计的接口,而前面定义的stat group和stat id则是上层的封装,你完全可以直接调用FThreadStats::AddMessage去给UE增加一个统计,但是这个只会记录在统计文件里,不能像stat group那样使用控制台指令实时打印在游戏界面上。

 

这里面除了上面这种最常规的定义一个cpu时间统计的方法,还有很多其他有用的宏方法:

QUICK_SCOPE_CYCLE_COUNTER(Stat):不需要你事先声明一个group,也不需要事先声明一个statid,用这个stat名字作为statid,在STATGROUP_Quick里面定义一个cycle的统计

DECLARE_SCOPE_CYCLE_COUNTER(CounterName,Stat,GroupId):声明一个在groupid组下的叫做countername的statid,并且立即启动一个它的scopecyclecounter,这也是一个在代码里快捷加cycle 统计的方法。

DECLARE_STATS_GROUP_VERBOSE:声明一个默认不被enable的组

CONDITIONAL_SCOPE_CYCLE_COUNTER(Stat,bCondition):只有在bCondition为true的情况下才统计

此外可以定义上面除了int类型之外的cycle counter之外,还可以定义其他类型,使用

DECLARE_FLOAT_COUNTER_STAT

DECLARE_DWORD_COUNTER_STAT

此外cycle counter还可以使用累计模式,即每帧不清空,即统计的是到当前为止的累计值,使用DECLARE_FLOAT_ACCUMULATOR_STAT这样的宏

 

除了对cpu cycle的统计之外,stat系统还可以统计其他一些指标,包括:

DECLARE_MEMORY_STAT 将声明一个int64的累计的计数器,通常用于统计内存,这种statid通常不用cycle count那种定义FScopeCycleCounter来使用,而是直接在代码里利用INC_MEMORY_STAT_BY/DEC_MEMORY_STAT_BY 来手动加减,它其实相当于调用FThreadStats::AddMessage() 给他发一个EStatOperation::Add/substrct消息。

当然所有stat都可以调用这个手动加减的接口,甚至还有直接设置每个stat的当前数值的接口SET_DWORD_STAT_FName。

 

上面列举了各种眼花缭乱的stat定义方法,但是其实这些多种多样的统计宏的背后的机制是简单纯粹的,就是在各种使用这个宏定义

DECLARE_STAT(Description, StatName, GroupName, StatType, bShouldClearEveryFrame, bCycleStat, MemoryRegion) 和FThreadStats::AddMessage()这两个机制。把这个机制抽象起来,可以这样描述:

1.首先在STAT系统定义了一种计数器,通过上面DECLARE_STAT这个宏去生成一个叫做FStat_##StatName的计数器的类型,这个类型要返回一些接口,用来描述:GroupName-属于哪个组,StatType-计数器的数据类型 ,bShouldClearEveryFrame-是否每帧清空,还是累加,bCycleStat-是否用来统计cpu cycle,MemoryRegion-是否是对memory的统计,如果是统计的mem类型是什么。

2.定义一个通常是全局的FThreadSafeStaticStat<FStat_##Stat> StatPtr_##Stat来方便的获取某个stat 名字的statid计数器类型

3.使用FThreadStats::AddMessage(FName InStatName, EStatOperation::Type InStatOperation) 这个机制去操纵某个stat计数器的值。InStatName就是这里的stat的名字,InStatOperation包括的操作包括:CycleScopeStart和CycleScopeEnd -将这段时间内的cpu 时间ms记录下来加到计数器里, Set-直接设置计数器的值,Clear-清空计数器的值,Add-增加计数器的值,Subtract-减少计数器的值。

所以上面的各种宏只是对上面这三个步骤的各种简化封装。

 

Stat系统给我们提供了一个基于埋点的统计函数cpu时间的机制,它很强大,我们可以通过stat group去动态看到这些时间(那些默认enable的),也可以通过ue的profilor去看各个计数器的时间曲线。但是很多时候当我们不能预感到哪里会有瓶颈的时候,即不知道在哪里埋点的时候,就需要更通用一些的机制。就依托一些平台的工具了。

 

平台工具

XCode的counter

counter是xcode在instrument里面的一个工具,他可以记录cpu上每个线程在一段时间内的各个函数的cpu占用时间比,对于ios系统来说,这个是衡量cpu帧率瓶颈的golden rule。Counter看到的具体内容可以如下:

 

如何从Counter来推测出每个函数的每帧具体时间开销呢?Counter给的是一个cpu的时间占比,我们可以先看到具体gamethread占用cpu的时间比r,然后从ue的stat unit得到gamethread的每帧时间t,然后对于一个具体函数它的cpu时间占比如果是b,那么这个函数平均每帧的执行时间就是t*b/r.

 

Android Studio的profiler

Android Studio3.0以上的profiler很强大,如果device是8.0以上的android系统,那么将可以用profilor capture一段时间的c++即android trace。然后可以从图表中看到当前每个thread中每个函数的cpu占用时间比,执行次数,等等,如图

 

还可以看到具体的每个线程每个函数执行的时序,如图

 

通过这个profiler不仅可以像xcode的counter一样获取所有c++函数的每帧执行时间,找到热点函数,我们还可以从thead的执行时许上直观看到多线程之间的函数执行关系,多线程的执行状态是否合理,比如看到game线程在某个地方需要等待很久某个work线程完成,那么可以尝试把work再分并行,或者调整某些无关的事情提前,让game等这个work的同时在做一些别的工作,不要干等。

 

Android NDK的 simpleperf

对于低版本无法使用android studio profiler调试的可以依赖Android sdk里面的另外两个有用的工具,一个是NDK的simpleperf,它可以调试获取c++层每个函数的cpu占用百分比,除了需要用命令行并且输出的格式没那么好看之外,同studio的profilor能拿到的结果是差不多的。

Simpleperf的完全使用文档在https://developer.android.com/ndk/guides/simpleperf,其实主要分为两步,第一步是用simperperf record命令去采集数据,第二步是用simpleperf report命令去输出数据。

一种比较简单的使用方法是这样的,首先连接手机,运行程序,确保在usb调试状态下,首先进入ndk的simpleperf目录下,打开app_profiler.config去配置一些配置,一定要配置的包括:

App_package_name:包名

Android_sudio_projectdir:android sdutio工程路径,这个在ue工程就是目录client/intermediate/android/apk/gradle/

Native_lib_dir:这个是用来寻找带调试符号的so的地址,在UE工程就是client/intermediate/android/apk/jni/armeabi-v7a/这个目录,因为shipping版本的符号没有,所以这里要提供在develop等版本编译出来的。

Apk_file_path:这是你的apk的路径

Main_activity:这个对于UE程序一般默认是com.epicgames.ue4.GameActivity

Record_option: 这个比较重要,要参加文档,是record的参数,例如”-e cpu-clock:u –duration 5”就代表采样cpu时钟数,并且仅监控用户空间,采样5秒。至于这里-e还可以采集哪些东西,你可以执行adb shell run-as com.xxx.xxx ./simpleperf list来列出来。

Adb_path:这里要填本机的adb工具的位置

 

配置好了,我们可以先启动你的可调式版本的程序在手机上,不能是shipping版本。然后正常情况我们需要做一系列上传符号,找psid,获取各种环境信息的操作给simperf,不过这个simpleperf下面有个快捷的app_profiler.py,它帮我们做好了,我们先python app_profilor.py执行这个py文件就好了。这个过程可能很慢,尤其是上传调试符号,它会代替手机上目录里面的so,所以对于一个手机的一次app安装,这个操作python脚本只要执行一次就好,不执行的话可能结果里面找不到符号信息。

等这个执行好了,我们先找到这个程序的pid,利用adb shell里面的ps命令能拿到

这时我们就可以进行一次采集,比较常见的采集指令是

Adb shell run-as com.xxx.xxx

./simpleperf record -e cpu-clock:u --duration 5 –p pid --symfs .

 

采集好后,我们可以通过simpleperf report指令来查看结果。

最简单的指令是./simple report –pids pid 通过这个指令可以看到这个进程里面所有线程的各个函数在这段采集时间的cpu占用百分比。如图:

 

可以看到这个看上去比较乱,我们想逐个线程,并且按照一定排序来看,所以可以先显示各个线程的

使用 ./simpleperf report --pids pid --sort tid,comm可以得到

 

这样我们就可以先一眼看出主要的几个线程的总的开销,有UE开发经验的同学肯定一眼就能认出这些线程,其实这里的thread-1884就是game线程了,然后我们再一点点的看每个线程就好了,我们使用./simpleperf report --pids pid –tids 1206 –g来打印rhi线程上的cpu占用,-g表示打印调用关系,我们可以得到

 

可以看到很清晰rhi线程上的函数开销,这个百分比是占整个rhi线程的,不是占整个进程的,配合stat unit这样的指令,如果我们知道rhi线程的时间,就能得到每帧某个函数的执行时间,因为rhi线程是api的提交线程,所以排名靠前的除了cp内存就是一些cmdbuff的执行函数了。

 

Android SDK的systrace

上面的simpleperf是个对于所有android系统不用root不用特殊工具就能得到的一种通用的函数开销分析,在android sdk下有个systrace,可以得到除cpu函数占用外的另外一些信息,包括比较有用的cpu-gpu trace,线程的工作状况等,也可以用来代替studio里面的线程工作查看功能。具体用法是,首先它的完整文档可以参考

https://developer.android.com/studio/profile/systrace/command-line。

我们进入android sdk的platform-tools下面的systrace文件夹下面,Systrace主要利用了

里面的systrace.py这个命令脚本,采集一段trace,并保存成一个html文件,用来查看。常用的用法是:

python systrace.py –t 5 –a appname -o mynewtrace.html gfx view sm sched idle load

这里面表示做一次5秒的systrace,将其输出到mynewtrace.html,然后后面是这次trace要采集的内容,具体能采集哪些内容可以使用python systrace.py --list-categories来得到。我们采集后就会生成这个html文件。

下面是查看,很多软件可以查看trace文件,简单的方法是打开chrome浏览器,输入chrome://tracing,就能打开这个trace查看工具,然后load加载你的html文件,就可以看到这个trace图形结果了。如图

 

我们去聚焦一些有用的东西:

比如观察cpu的trace,可以看到每个核上正在执行的线程执行的任务

 

又比如我们观察下面几行,就可以判断当前cpu还是gpu的瓶颈。我们看SurfaceView即可以认为是GPU的绘制时间,大约10ms之内,而最下面RenderThread2上的eglswapbuf是cpu给gpu每帧最后做提交的截止,两次eglswapbuffer直接的间隔高达53ms,说明当前是明显的cpu瓶颈。

 

Lua层的函数瓶颈分析

前面我们一直在讨论C++这层的瓶颈,大部分手游可能会在c++上使用lua开发,上面的工具都不直接支持对Lua的热点函数分析,只能得到lua虚拟机的执行时间,我们就需要给lua层提供一种分析方法。

我们可以利用Lua的Debug库,Lua虚拟机自带了一个Debug库,文档可参考https://www.lua.org/pil/23.html,用它可以获取到丰富的lua层的profile信息,最关键的是要为lua设置一个钩子,即debug.sethook,我们勾住每一次函数的call和return,即使用”cr”选项,然后在钩子事件中,我们又可以通过debug.getinfo获得当前勾住的函数信息,我们既然已经能够知道每次函数的调用和返回时机,剩下的工作就是写一些统计性的代码了。

 

卡顿问题

在最前面我们说低帧率和卡顿是两种性质的问题,找到卡顿问题一般只能使用埋点的方式,即基于UE的stat系统,观察stat的曲线,找到每个峰值。但是问题是为了发现某个位置的卡顿,这些点应该埋在哪里?毕竟UE默认的stat为我们埋的点并不能覆盖所有地方。

我们一般可以基于UE的主线逻辑去不断的做二分(或N分):

UE虽然是一个复杂的多线程工作的系统,但是其GameThread是控制分配其他所有线程的,所以理论上所有线程的卡顿最终都能被反应到GameThread上,而RenderThread和RHI thread是另外两个比较容易出瓶颈的大线程,所以一般上我们能够在这三个大线程上埋好点就可以了。

GameThread:GameThead的每帧的逻辑tick的主流程在FEngineLoop::Tick里面,我们可有通过不断的对这个函数用scopecounter细分埋点来定位卡顿的来源。

RenderThread:RenderThread是一个命令队列,由GameThread充填,只要这个队列里有命令它就会持续执行,UE使用一些统一的宏去把命令加入队列,包括ENQUEUE_UNIQUE_RENDER_COMMAND(TypeName,…)这些宏等,我们很自然的能够想到只要在这些宏里面执行指令的时候加入一个scopecounter就可以了,就能先统计到每个渲染指令的大入口的开销,其实ue已经这样做了,它会为每个渲染指令在STATGROUP_RenderThreadCommands这个组下面生成一个叫做TypeName的stat。当我们找到了那个具体的RenderThread的卡顿点的时候,可以自己进入这个命令的执行函数里面进一步二分去定位。RenderThread里面通常来说比较容易成为瓶颈的大指令函数包括FMobileSceneRenderer::Render,FSlateRenderer::DrawWindow等,这些可以看做渲染的每帧主循环,要在里面进一步细分。

RHIThread:RhiThread也是一个命令队列,由Render或者game填充并驱动指令,负责图形API的调用。RHI命令继承自FRHICommand,并且从ExecuteAndDestruct函数执行,所以我们其实可以在这里加入一个通用的scopecounter做统计,然后找到是哪个rhicommand是瓶颈之后再进一步在指令的excute执行函数里面细分下去。对于RHIThread的更细致的瓶颈分析在本系列之前的一篇文章中专门分析过,https://blog.csdn.net/leonwei/article/details/95527109,可以参考。

 

对于Render和rhi线程,他们的卡顿在stat图表上看最终都会导致gamethread的卡顿,gamethread表现在卡在Wait for event或者SyncFrameEnd上,都表示game有可能卡在渲染任务上,wait for event是因为gamethread确实已经无事可做,而还要受taskgraph上其他依赖的线程的完成,可能是渲染线程,syncframeend则是game在执行完一帧结束的时候要检查是不是至少上一帧的rhi执行完毕。

 

由于game是render和rhi的源驱动,所以通常我们在确定render和rhi卡顿的时候需要进一步追溯到是game的哪一步逻辑导致的render和rhi的卡,即”第一现场”,这里面需要排除一些多线程的因素,一种方法是我们强制单线程,即使用”-onethread”来启动,但是这种设置可能会很卡或者运行不正常,另一种是在多线程下配合各种强制同步方法,包括:

调用FlushRenderingCommands在gamethread强行等待当前所有renderthread的指令以及rhithread中的指令全执行完,相当于一次完整的对渲染线程的强制同步,
调用GRHICommandList.GetImmediateCommandList().ImmediateFlush()则是只强制将rhithread的指令执行完毕,相当于只强制同步rhi线程
调用 GRHICommandList.GetImmediateCommandList().BlockUntilGPUIdle()则会强制把当前的的所有rhi中指令执行完毕,并且把commandbuffer发送给gpu,并且等待gpu执行完成,相当于一个强制同步到GPU的过程。
我们可以通过在某些逻辑处应用这些同步接口来在局部模拟类似单线程的情形来定位渲染上的”第一现场”。

 

除了Render和RHI之外,game线程在工作的时候会派发很多工作线程出去,这些对game的继续推进有前置依赖的任务如果没有执行完,也会导致gamethread表现的卡顿,但是其实是卡在了某个其他任务线程上,game会表现在卡在wait for event上,这时候第一要去查看其他的thread的工作情况,看看是否某个game等待的工作线程做的太久,另一种情况就是没有找到哪个线程工作的很久,大家都在wait,这时候要分析这个包含这个wait event的函数的逻辑,说明没有哪个线程在满载运行,可能因为:

逻辑设计的不合理,线程间互相等待
等待IO
等待了某个需要被延时触发的事件
等待某个昂贵的操作,但是这个操作有又被不合理的大量分帧,所以看上去在没帧内没有哪个线程工作饱满,但是就是在等。
总之这种没有明显特征的wait要具体分析wait处的逻辑,另外要理解ue的taskgraph,asynctask等系统才会有更大帮助。

 

Stat Hitches

除了基于stat系统埋点之外,UE还提供stat hitches这套指令。Stat埋点的方法通常需要我们去录很长一段数据,可能一些卡顿不是容易出现的,录一段很长的stat数据打开也不方便。Stat Hitches这套指令是动态的去发现当前某一阵是否为卡顿帧(其实它是设置了一个阈值),然后选择将其显示出来,或者保存当前帧前后的stat数据。一般用法是先设置 t.HitchFrameTimeThreshold 定义卡顿的帧时间阈值,然后用指令stat hitches可以直观看到掉帧时的屏幕显示,用指令stat DumpHitches则可以将掉帧时候的stat数据保存下来及输出到控制台。

 

对于UE程序有很多种方法分析帧率瓶颈及卡顿的性能问题,解决问题的前提是找到问题,而找到问题的前提是找到或者制作合适的工具来捕捉到问题。作为引擎和游戏的优化开发人员,无论是什么机型,只要安装我们的版本,我们就可以从上面的方法中至少找到一个有效的方法定位问题,才能做到不慌,保证问题得到解决。