UI 卡顿问题复现及分析
在进行 NVIDIA Omniverse USD 插件开发的时候遇到了一个性能卡顿的问题，这个功能的初衷是通过路径追踪和原始的绿幕视频，借助 Omniverse Farm 来实现高质量的后期自动化流程，实现思路是记录相机定位 FreeD 的运动轨迹，并记录保存到一个 USD 的 sublayer 当中，根据时间码（Timecode）进行后期自动化合成的流程，流程图如下：
在外部摄影机记录原始的绿幕影片素材的时候，点击开始 / 结束分别会触发一个时间码 （Timecode）的信号，信号可以在 BMD 采集卡当中通过 SDK 获得，这样我们把从开始到结束的相机定位轨迹记录存至 buffer 中，然后更新到 USD 的 stage sublayer 中。
首先通过 Python API 创建一个 Sublayer，把记录的 sequence 通过 USD time sampler 记录到相机 prim 的 attribute 下面，仅对一万个 time sampler 进行记录并统一写入该 sublayer，后观察到该写入过程耗时达数十秒，且造成 Omniverse 主线程 UI 出现卡顿。经测试，无论采用同步、异步 AsyncIO 或线程方式执行操作，均未使情况得到改善，UI 卡死现象始终存在。（可以查看代码文件中注释的 1、2、3）
Tracy.py 的源代码如下：
importomni.kit.app
importtime
importasyncio
frompxrimportSdf, Usd, UsdGeom, Gf
fromomni.kit.usd.layersimportLayerUtils, get_layers, LayerEditMode
importomni.kit.commands
fromcollectionsimportdeque
importos
fromtypingimportList,Tuple
fromomni.kit.widget.layers.path_utilsimportPathUtils
importcarb
fromtypingimportList,Tuple
fromenumimportEnum
importasyncio
frompxrimportSdf, Usd, UsdGeom
frompxrimportUsd, UsdGeom, Gf
fromomni.kit.async_engineimportrun_coroutine
fromconcurrent.futuresimportALL_COMPLETED, ThreadPoolExecutor, wait
defcreate_prim(stage, prim_path="/World/Camera"):
prim = stage.GetPrimAtPath(prim_path)
ifprimandprim.GetTypeName() =="Camera":
carb.log_info(f"Camera already exists at:{prim_path}")
returnprim
else:
camera_prim = UsdGeom.Camera.Define(stage, prim_path)
camera_prim.AddTranslateOp().Set(Gf.Vec3d(10,20,30))
camera_prim.AddRotateXYZOp().Set(Gf.Vec3f(0,45,0))
carb.log_info(f"Created new Camera at:{prim_path}")
returncamera_prim.GetPrim()
classTestClass:
def__init__(self):
self._rotate_queue = deque()
self._translate_queue = deque()
self._pts_queue = deque()
self._pts =0
self._Layer_num =0
defcreate_sublayer(self, _root_layer, strLayerName, orderIndex, bSetAuthoring):
#layname =
self._Layer_num +=1
identifier1 = LayerUtils.create_sublayer(_root_layer, orderIndex, strLayerName).identifier
#
ifbSetAuthoring:
omni.kit.commands.execute("SetEditTargetCommand", layer_identifier=identifier1)
defprepare_data(self):
begin = time.time()
rotation_1 = Gf.Vec3f(0.0,0.0,0.0)
_translate = Gf.Vec3d(0.0,0.0,0.0)
for_inrange(10000):
self._rotate_queue.append(rotation_1)
self._translate_queue.append(_translate)
end = time.time()
carb.log_info(f"prepare_data elaspe:{end - begin}")
asyncdefawait_flush_save(self):
carb.log_info("before await_flush_save {time.time()}")
awaitomni.kit.app.get_app().next_update_async()
self.flush_save()
carb.log_info("end await_flush_save {time.time()}")
defflush_save(self):
timecode =0
whileself._rotate_queueorself._translate_queue:
ifself._rotate_queue:
f_val = self._rotate_queue.popleft()
self._rotation_ops.Set(time = timecode, value = f_val)
ifself._translate_queue:
d_val = self._translate_queue.popleft()
self._translate_ops.Set(time = timecode, value = d_val)
timecode +=10
self._render_update_sub =None
asyncdefawaitflush(self):
awaitomni.kit.app.get_app().next_update_async()
self.flush_save(self)
asyncdefflush_save_async(self):
time0 = time.perf_counter()
carb.log_info("flush_save_async begin")
loop = asyncio.get_running_loop()
# 直接调用同步函数（主线程），但用await asyncio.sleep(0)切分事件循环
awaitloop.run_in_executor(None, self.flush_save)
time1 = time.perf_counter()
carb.log_info(f"flush_save_async end elaspe:{time1 - time0}")
definit_stage_camera(self, stage, camera_prim_path):
self._stage = stage
self._camera_path = camera_prim_path
self._camera_prim = UsdGeom.Camera.Get(stage, camera_prim_path).GetPrim()
xform_ops = UsdGeom.Xformable(self._camera_prim).GetOrderedXformOps()
foropinxform_ops:
ifop.GetOpType()in[UsdGeom.XformOp.TypeRotateXYZ,
UsdGeom.XformOp.TypeRotateXZY,
UsdGeom.XformOp.TypeRotateYXZ,
UsdGeom.XformOp.TypeRotateYZX,
UsdGeom.XformOp.TypeRotateZXY,
UsdGeom.XformOp.TypeRotateZYX]:
#rotation = op.Get()
self._rotation_type = op.GetOpType()
self._rotation_ops = op
#print(f"rotation is {rotation}")
elifop.GetOpType() == UsdGeom.XformOp.TypeScale:
self._scale_ops = op
elifop.GetOpType() == UsdGeom.XformOp.TypeTranslate:
self._translate_ops = op
if__name__ =="__main__":
_stage = omni.usd.get_context().get_stage()
root_layer = _stage.GetRootLayer()
prim_path ="/World/Camera"
new_layer_path ="d:/camera_sublayer.usd"
runclass = TestClass()
create_prim(_stage, prim_path)
runclass.init_stage_camera(_stage, prim_path)
runclass.create_sublayer(root_layer, new_layer_path,0,True)
runclass.prepare_data()
begin = time.time()
carb.log_info(f"before run coroutine")
#(1)Async block UI for about 50 seconds
run_coroutine(runclass.await_flush_save())
#(2)Also block UI about 50 seconds
# with ThreadPoolExecutor() as executor:
# executor.submit(runclass.flush_save())
#(3)Sync, same block
#self.flush_save()
end = time.time()
carb.log_info(f"elaspe time is{end-begin}， 10000 ends")
* 附代码链接：https://github.com/slayersong/OVPerf_Tracy/blob/main/tracy_profiler.py（复制链接至浏览器打开）
复现问题：打开菜单中的Developer --Script Editor，打开 tray_profiler.py 文件，然后点击 Run，可以看到创建了一个 camera_sublayer，并且主 UI 卡住了几十秒无响应。
需要注意的是，在 Omniverse USD 的 layer 层级继承覆盖当中，在上层的 Layer 的行为会覆盖下层的 layer，关于 USD layer 层级的关系，请查看本文结尾提供的 DLI 课程链接。
然后在 Content Browser 中单击鼠标右键，选择 Edit，可以看到数据成功写入了 USD 文件，只是中间卡顿的时间过长。
分析：在遇到 Profiler 的时候不要盲猜，可能是 memory、IO Bound、Compute Bound 或者一些不太能想到的情况，这时候则需要利用专业化的工具进行分析定位，找到问题所在并解决，比如可以利用著名工具Tracy（https://github.com/wolfpld/tracy），该工具可以分析 CPU / GPU 性能瓶颈，并支持主流 Graphics API：DX、Vulkan、OpenGL、CUDA 等，且 Omniverse 已经把该工具与 Omniverse Kit 进行了集成。因此可以利用 Tracy 去看底层的 CallStack 里什么影响了这个操作，在 Omniverse 当中，Tracy 已经配置好了 Symbol 符号表， 可以看到底层的代码函数调用堆栈，后而寻找具体是什么情况卡住了不正常的几十秒时间。
Tracy 的使用
2.1 操作介绍
Omniverse 已经集成了 Tracy 的开发集成插件：https://docs.omniverse.nvidia.com/extensions/latest/ext_profiler_tracy.html
Tracy 本身是一个著名的分析工具，具体的菜单操作可以参考知乎这个帖子：https://zhuanlan.zhihu.com/p/1915041165033607442
UI 操作的详细讲解可参考如下视频：
Tracy 讲解文档
视频参考：
https://www.bilibili.com/video/BV1or421J7Du/?spm_id_from=333.337.search-card.all.click
文档参考：
https://github.com/CppCon/CppCon2023/blob/main/Presentations/Tracy_Profiler_2024.pdf
2.2 安装
首先打开菜单 Developer -- Extension 搜索，找到 Profiler Tracy 并且安装。
然后会出现一个新的 Profiler 菜单，点击 Profiler --Tracy --Launch and Connect。
Tracy 基本使用操作：
1. Pause：在实时监测到发生性能瓶颈的事件以后要暂停，否则时间轴会一直向右走
2. 按住鼠标右键可以拖动到你想要的位置
3. 鼠标滚轮：Zoom in / out
2.3 分析问题
运行上述代码，点击 Tracy 中的 Pause 暂停（不暂停 Tracy 会一直记录的一直滚动）。之后按住 Ctrl 和鼠标中间的滚轮，Zoom 缩小操作，可以很容易找到一个最大的耗时，从 11 秒开始到 31 秒，这一个 Frame Render 用了二十几秒（注意：函数的调用堆栈已经正确显示)，可以发现卡在了 RenderThread 中的usd_mutex_wait函数上面：
这样通过 Tracy 的使用就明白了问题卡住的大致原因，简而言之，渲染线程会等待 USD 写入的结束，一直卡在usd_mutex_wait。
2.4 解决问题
分析：该问题的本质其实是 USD 的写入与修改会非常的慢，这是 USD 的基础架构造成的。
单单针对这个问题解决的方法不复杂，可以思考一下，写入的 Sublayer 其实并不需要实时参与 USD Composite， 因为我们并不需要实时观察到合成结果，可以创建离线的 Sublayer ，等待写入结束以后再自动或者手动把 Sublayer 加入进来，代码如下，看到并没有卡顿这一个过程，那么问题就解决了。
针对此次问题的 Solution 如下：
importomni.kit.app
importtime
importasyncio
frompxrimportSdf, Usd, UsdGeom, Gf
fromomni.kit.usd.layersimportLayerUtils, get_layers, LayerEditMode
importomni.kit.commands
fromcollectionsimportdeque
importos
fromtypingimportList,Tuple
fromomni.kit.widget.layers.path_utilsimportPathUtils
importcarb
fromtypingimportList,Tuple
fromenumimportEnum
importasyncio
frompxrimportSdf, Usd, UsdGeom
frompxrimportUsd, UsdGeom, Gf
fromomni.kit.async_engineimportrun_coroutine
fromconcurrent.futuresimportALL_COMPLETED, ThreadPoolExecutor, wait
defcreate_prim(stage, prim_path="/World/Camera"):
prim = stage.GetPrimAtPath(prim_path)
ifprimandprim.GetTypeName() =="Camera":
carb.log_info(f"Camera already exists at:{prim_path}")
returnprim
else:
camera_prim = UsdGeom.Camera.Define(stage, prim_path)
camera_prim.AddTranslateOp().Set(Gf.Vec3d(10,20,30))
camera_prim.AddRotateXYZOp().Set(Gf.Vec3f(0,45,0))
carb.log_info(f"Created new Camera at:{prim_path}")
returncamera_prim.GetPrim()
classTestClass:
def__init__(self):
self._rotate_queue = deque()
self._translate_queue = deque()
self._pts_queue = deque()
self._pts =0
defregis(self):
self._app = omni.kit.app.get_app()
self._render_update_sub = self._app.get_update_event_stream().create_subscription_to_pop(
self.pre_frame_render, order=-10, name="gm_render_event")
defpre_frame_render(self,e):
self._pts +=1
self.get_push_pos_rotate(self._pts)
ifself._pts ==1000:
begin = time.time()
carb.log_info(f"before run coroutine")
run_coroutine(self.await_flush_save())
#self.flush_save()
carb.log_info(f"end run coroutine")
end = time.time()
carb.log_info(f"elaspe time is{end-begin}")
self._render_update_sub =None
defget_push_pos_rotate(self, pts):
rotae = self._rotation_ops.Get()
translate = self._translate_ops.Get()
self._rotate_queue.append(rotae)
self._translate_queue.append(translate)
self._pts_queue.append(pts)
defprepare_data(self):
begin = time.time()
rotation_1 = Gf.Vec3f(0.0,0.0,0.0)
_translate = Gf.Vec3d(0.0,0.0,0.0)
foriinrange(500):
# rotation_1 = Gf.Vec3f(0.0, 0.0, 0.0)
# _translate = Gf.Vec3d(0.0, 0.0, 0.0)
rotation_1 = Gf.Vec3f(-253.0, i * (360.0/499),93) # 99是为了最后一次达到360
# _translate的xyz从0递增到100
_translate = Gf.Vec3d(2124.0, 2124.0, 104)
self._rotate_queue.append(rotation_1)
self._translate_queue.append(_translate)
end = time.time()
carb.log_info(f"prepare_data elaspe:{end - begin}")
asyncdefawait_flush_save(self):
carb.log_info("before await_flush_save {time.time()}")
awaitomni.kit.app.get_app().next_update_async()
self.flush_save()
carb.log_info("end await_flush_save {time.time()}")
defflush_save(self):
timecode =0
whileself._rotate_queueorself._translate_queue:
ifself._rotate_queue:
f_val = self._rotate_queue.popleft()
#self._rotation_ops.Set(time = timecode, value = f_val)
self.seq_write_rotate_op.Set(time = timecode, value = f_val)
ifself._translate_queue:
d_val = self._translate_queue.popleft()
self.seq_write_translate_op.Set(time = timecode, value = d_val)
#self._translate_ops.Set(time = timecode, value = d_val)
timecode +=10
self._sub_stage.GetRootLayer().Save()
self._render_update_sub =None
asyncdefawaitflush(self):
awaitomni.kit.app.get_app().next_update_async()
self.flush_save(self)
asyncdefflush_save_async(self):
time0 = time.perf_counter()
carb.log_info("flush_save_async begin")
loop = asyncio.get_running_loop()
# 直接调用同步函数（主线程），但用await asyncio.sleep(0)切分事件循环
awaitloop.run_in_executor(None, self.flush_save)
time1 = time.perf_counter()
carb.log_info(f"flush_save_async end elaspe:{time1 - time0}")
defcreate_offline_layer(self, layer_base_path, prim_path, bOverride):
# split name and ext
name, ext = os.path.splitext(layer_base_path)
index =1
new_layer_path = layer_base_path
#If exist create a new path such as basepath_1.usd
whileos.path.exists(new_layer_path):
new_layer_path =f"{name}_{index}{ext}"
index +=1
new_layer = Sdf.Layer.CreateNew(new_layer_path)
# 2. 打开该layer对应的Stage（编辑该layer）
self._sub_stage = Usd.Stage.Open(new_layer)
# 3. 以over方式定义相机Prim（覆盖已有的/world/Camera）
ifbOverride:
self._seq_camera_prim = self._sub_stage.OverridePrim(prim_path)
self._seq_camera_prim.SetSpecifier(Sdf.SpecifierOver)
else:
self._seq_camera_prim = self._sub_stage.DefinePrim(prim_path)
# 4. 获取或创建Xformable接口，用于添加变换操作
xformable = UsdGeom.Xformable(self._seq_camera_prim)
# 5. 添加translate和rotateXYZ操作
self.seq_write_translate_op = xformable.AddTranslateOp()
self.seq_write_rotate_op = xformable.AddRotateXYZOp()
definit_stage_camera(self, stage, camera_prim_path):
self._stage = stage
self._camera_path = camera_prim_path
self._camera_prim = UsdGeom.Camera.Get(stage, camera_prim_path).GetPrim()
xform_ops = UsdGeom.Xformable(self._camera_prim).GetOrderedXformOps()
foropinxform_ops:
ifop.GetOpType()in[UsdGeom.XformOp.TypeRotateXYZ,
UsdGeom.XformOp.TypeRotateXZY,
UsdGeom.XformOp.TypeRotateYXZ,
UsdGeom.XformOp.TypeRotateYZX,
UsdGeom.XformOp.TypeRotateZXY,
UsdGeom.XformOp.TypeRotateZYX]:
#rotation = op.Get()
self._rotation_type = op.GetOpType()
self._rotation_ops = op
#print(f"rotation is {rotation}")
elifop.GetOpType() == UsdGeom.XformOp.TypeScale:
self._scale_ops = op
elifop.GetOpType() == UsdGeom.XformOp.TypeTranslate:
self._translate_ops = op
if__name__ =="__main__":
_stage = omni.usd.get_context().get_stage()
prim_path ="/World/Camera"
new_layer_path ="d:\tes303.usda"
runclass = TestClass()
create_prim(_stage, prim_path)
runclass.init_stage_camera(_stage, prim_path)
runclass.create_offline_layer(new_layer_path, prim_path,True)
carb.log_info("create_offline_layer after")
#runclass.regis()
runclass.prepare_data()
begin = time.time()
carb.log_info(f"before run coroutine")
run_coroutine(runclass.flush_save_async())
#run_coroutine(runclass.await_flush_save())
#runclass.flush_save()
carb.log_info(f"end run coroutine")
#runclass.flush_save()
# with ThreadPoolExecutor() as executor:
# executor.submit(runclass.flush_save())
end = time.time()
carb.log_info(f"elaspe time is{end-begin}， 1000 ends")
# class YourClass:
# def __init__(self):
# # 初始化队列等
# pass
# def flush_save(self):
# # 这是同步函数，不能改动
# # 里面调用了Omniverse API，必须在主线程执行
# print("Begin flush save")
# time.sleep(1)
# print("end flush save")
# async def flush_save_async(self):
# time0 = time.perf_counter()
# print("run task begin")
# loop = asyncio.get_running_loop()
# # 直接调用同步函数（主线程），但用await asyncio.sleep(0)切分事件循环
# await loop.run_in_executor(None, self.flush_save)
# time1 = time.perf_counter()
# print(f"run task end elaspe:{time1 - time0}")
# async def testawait():
# pass
# # obj = YourClass()
# # run_coroutine(obj.flush_save_async())
# # print(f"run pass the async")
# # count = 0
# # def pre_frame_render(e):
# # #print(f"Frame Begin: {app.get_update_number()} {e.payload}, event-type {e.type}, {time.time() * 1000 % 1000000} ")
# # asyncio.ensure_future(obj.flush_save_async())
# # async def run_task():
# # time0 = time.perf_counter()
# # print("run task begin")
# # await obj.flush_save_async()
# # print("run task end")
# # time1 = time.perf_counter()
# # elapse_time = time1 - time0
# # print(f"run taks elapse is {elapse_time}")
# # def frame_render(e):
# # print(f"Frame Render: {app.get_update_number()} {e.payload}, event-type {e.type}, {time.time() * 1000 % 1000000}")
# # def post_frame_render(e):
# # print(f"Frame End: {app.get_update_number()} {e.payload}, event-type {e.type}, {time.time() * 1000 % 1000000}")
# first_last_event = 1000000
# # pre_update_sub = app.get_pre_update_event_stream().create_subscription_to_pop(
# # pre_frame_render, order=-first_last_event, name="gm_frame_begin")
# #asyncio.ensure_future(obj.flush_save_async())
* 附代码链接：https://github.com/slayersong/OVPerf_Tracy/blob/main/solution_%20tracy_profiler.py
但是在一些项目当中一定要实时观察到结果。比如，有很多的数字孪生的工业场景中会存在小车传送带，各种物品都是实时进入到场景管线当中，这其中必定要参与 USD 合成。
所以这里介绍一个 Omniverse 对 USD 进行重构的基本概念 Fabric，USDRT（USDRT 是 Fabric 的 API），NVIDIA 在 Omniverse 当中开发了 Fabric 组件专门处理 USD 实时更改缓慢的问题：
https://docs.omniverse.nvidia.com/kit/docs/usdrt/latest/docs/usd_fabric_usdrt.html
通过这个官方文档的图也验证了刚才的结论：Render 线程会等待 USD 的合成结果 Composed 后进行渲染。
结束：如果单解决这个问题其实并不复杂，但是其中需要用到很多的基础知识，包括 USD 的合成机制、多线程开发、遇到问题如何去利用工具定位分析等。后面我们将会对 USDRT 与 Fabric 进行更细致的讲解，包括代码的开发使用和 Omniverse 中其他性能工具的使用教程。也希望更多的朋友可以分享在 USD 开发过程当中的心得体会。
附录：
关于前面提到的 USD 的基本开发教程，包括 USD 合成机制，USD 基本动画 TimeSampler 等：
文案提供和技术支持：
宋毅明
NVIDIA Omniverse & OpenUSD 开发者关系经理
*与 NVIDIA 产品相关的图片或视频（完整或部分）的版权均归 NVIDIA Corporation 所有。
