使用性能计时器
在Nuke中打开性能计时器时,就可以通过Python读取性能信息。就能知道每个节点的运算时间。
在调试运行较慢的脚本,找出耗时瓶颈上很有帮助。
注意,打开性能计时器会影响Nuke的性能,因为会频繁打开、关闭计时器,同步线程。因此打开
此功能,Nuke会更慢,但是能让你获取nuke脚本处理时间的快照。
从命令行加上“-P” 会打开此功能,或者调用Python命令来打开计时器
nuke.startPerformanceTimers()
检查计时器是否允许性能计时器:
nuke.usingPerformanceTimers()
关闭计时器:
nuke.resetPerformanceTimers()
Nuke架构上的注意事项
当nuke内的节点要渲染时,有4个步骤:
- store -- 第一件事就是存下用户在knobs上选择的数据
- validate -- 节点告知Nuke其输出的信息,例如处理的哪个通道,以及大小
- request -- 在这节点弄明白了其需要哪些输入才能产生对应的输出(例如,需要通道,需要区域)
- engine -- 在这节点干了大部分的工作,并输出。这也是花费时间最多的地方。
更多信息,请看nuke 开发文档
通过python获取能耗时间
Nuke的性能计时器收集这四个处理阶段的信息,并可以通过python来获取。另外,性能计时器激活时,
计时信息会显示在节点图中。节点也会根据耗时比重显示不同的颜色,从绿(最快)到红(最慢)。
函数nuke.node.performanceInfo()会打印某个节点的时间信息。例如,下面的代码段就能
打印当前节点树种每个节点的时间信息(包括在 组内的节点):
for n in nuke.allNodes(recurseGroups=True):
print n.fullName()
print n.performanceInfo()
对一个简单的只有 Checkerboard-> Blur -> Defocus -> Viewer 的节点树输出和下面的很像:
Defocus1
{'callCount': 10228, 'timeTakenWall': 28524348, 'timeTakenCPU': 624512794}
Blur1
{'callCount': 9607, 'timeTakenWall': 9906815, 'timeTakenCPU': 151406143}
Viewer1
{'callCount': 0, 'timeTakenWall': 0, 'timeTakenCPU': 0}
CheckerBoard1
{'callCount': 34396, 'timeTakenWall': 3923322, 'timeTakenCPU': 29982254}
如上 nuke.Node.performanceInfo()返回了一个包含下列性能统计信息的字典:
- callCount 这个过程被调用的次数
- timeTakenWall 用墙上挂钟记录所花费的时间,用户实际要等待此处理要结束的时间。以毫秒计算。
- timeTakenCPU
- Linux上是CPU执行代码的时间,也是毫秒计时。是所有CPU上的用时总和。例如,多线程engine
的处理时间就要比实际用时长很多。如果平均CPU时间(timeTakenCPU初始使用的线程数)比每个线程执行
时间短,说明CPU线程花了很长时间但没有执行代码。例如,等待锁,说明性能又问题。 - MAC和Win上,CPU时间还不能用,Mac上这个值和处理的总时间差不多。
- Linux上是CPU执行代码的时间,也是毫秒计时。是所有CPU上的用时总和。例如,多线程engine
在Linux Nuke开24线程上获取的时间信息,我们看下最耗时的两个节点Blur和Defocus:
Defocus1
{'callCount': 10228, 'timeTakenWall': 28524348, 'timeTakenCPU': 624512794}
Blur1
{'callCount': 9607, 'timeTakenWall': 9906815, 'timeTakenCPU': 151406143}
Blur节点的CPU时间是 wall time的24倍,Defocus节点的CPU时间是我们期望值的三分之二。说明engine的线程
都被Blur节点占用了,同事Defoucs节点花费了相当长的时间来等待,同时我们也发现了以后优化Nuke的一个方向!
其他性能统计
默认,nuke.Node.performanceInfo()会给出engine处理部分,通常也是最好是部分的用时信息. 也可以
通过传入下面的参数获取其他处理部分的用时信息:
nuke.PROFILE_STORE
nuke.PROFILE_VALIDATE
nuke.PROFILE_REQUEST
nuke.PROFILE_ENGINE
例如,获取Defocus节点在上面的数中的所有用时,可以用下面的代码:
n = nuke.toNode("Defocus1")
print "Defocus1"
print "Store"
print n.performanceInfo(nuke.PROFILE_STORE)
print "Validate"
print n.performanceInfo(nuke.PROFILE_VALIDATE)
print "Request"
print n.performanceInfo(nuke.PROFILE_REQUEST)
print "Engine"
print n.performanceInfo(nuke.PROFILE_ENGINE)
结果如下:
# Result: Defocus1
Store
{'callCount': 108, 'timeTakenWall': 6571, 'timeTakenCPU': 6563}
Validate
{'callCount': 53, 'timeTakenWall': 1451, 'timeTakenCPU': 1445}
Request
{'callCount': 108, 'timeTakenWall': 1017, 'timeTakenCPU': 1009}
Engine
{'callCount': 10228, 'timeTakenWall': 28524348, 'timeTakenCPU': 624512794}
正如预料的,Defocus大部分时间花在了engine处理上,store,validate,request相对都很快.
如果并非如此,或者callCount显示store,validate,request调用次数很多,就说明这
是一个影响性能的问题了.
注意某些节点就是要比例子中的Defocus在store,validate,request阶段花费更多时间.例如,
reader在validate阶段更长,因为需要打开文件,如果是网络文件就会更慢. ScanlineReader节点
是另一个例子,validate要更长,同事store节点比RotoPaint更慢,因为需要bake曲线.带有耗时
表达式的knbo也会在store节点花费更多时间.
性能信息写入XML
当使用 "-Pf <filename>"参数运行nuke时,性能数据连带部分系统数据会自动写入XML文件.
此模式下,性能计时器会再渲染开始前启动,渲染结束后就讲数据写入xml文件. 当nuke在
此模式运行时,调用:
nuke.performanceProfileFilename()
会返回xml文件名。
网友评论