背景
上文介绍了kernel常用的测量方法，而实际应用中，还会遇到其他的问题，比如：
1. 为什么同样的输入，测量的耗时存在较大差距？
2. 怎样才能精确的测量kernel耗时？
问题
我们看以下以下常见代码，仅仅做了linear操作：
def test():
a_size = (20, 8192)
b_size = (5120, 8192)
events = [
[torch.cuda.Event(enable_timing=True) for _ in range(6)] for _ in range(50)
]
# warm up
for _ in range(10):
a = torch.rand(a_size, dtype=torch.float16).cuda()
b = torch.rand(
b_size,
dtype=torch.float16,
).cuda()
c = F.linear(a, b)
# 测量
for i in range(10):
a = torch.rand(a_size, dtype=torch.float16).cuda()
b = torch.rand(b_size, dtype=torch.float16).cuda()
events[i][0].record()
c = F.linear(a, b)
events[i][1].record()
events[i][2].record()
c = F.linear(a, b)
events[i][3].record()
events[i][4].record()
c = F.linear(a, b)
events[i][5].record()
torch.cuda.synchronize()
# 输出时间
for i in range(5):
print(
f"{i}: t1:{events[i][0].elapsed_time(events[i][1])},t2:{events[i][2].elapsed_time(events[i][3])},t3:{events[i][4].elapsed_time(events[i][5])}"
)
torch.cuda.synchronize()
if __name__ == "__main__":
test()
以上代码在A100上输出为：
可以看到，t1耗时远大于t2与t3，显然这不合理，同样的输入，计算时间不可能相差这么多，接下来我们逐步分析。
为什么同样的输入，测量的耗时相差巨大？
我们先对以上代码进行nsys分析：
观察到：三次linear在kernel层面只有60us+，但torch.cuda.event测量与nsys没对齐，第一次远大于kernel运行的时间。推测第一次torch.cuda.event测量的耗时并非kernel的耗时，应该包含了其他部分的耗时。
观察到代码：
a = torch.rand(a_size, dtype=torch.float16).cuda()
b = torch.rand(b_size, dtype=torch.float16).cuda()
存在cpu数据拷贝到gpu，猜测torch.cuda.event把拷贝的时间也算进去了，那我们去掉拷贝试试：
.....
for i in range(10):
# 改成直接从GPU生成rand数据，而不是拷贝
a = torch.rand(a_size, dtype=torch.float16, device="cuda")
b = torch.rand(b_size, dtype=torch.float16, device="cuda")
events[i][0].record()
c = F.linear(a, b)
events[i][1].record()
events[i][2].record()
c = F.linear(a, b)
events[i][3].record()
events[i][4].record()
c = F.linear(a, b)
events[i][5].record()
.....
测量结果为：
果然第一次的torch.cuda.event的正常了不少，但发现还是第1次比第2、3次大，继续观察nsys时间：
从nsys看，第1次linear是67us，而第2次kernel耗时是60us，第1次的确大于第2次耗时，由于两次运算是同样的数据，猜测是由于GPU缓存导致，可以尝试清空缓存：
fc = torch.empty(int(40 * (1024**2)), dtype=torch.int8, device="cuda")
def flush_cache():
fc.zero_()
...
for i in range(10):
a = torch.rand(a_size, dtype=torch.float16, device="cuda")
b = torch.rand(b_size, dtype=torch.float16, device="cuda")
flush_cache()
events[i][0].record()
c = F.linear(a, b)
events[i][1].record()
flush_cache()
events[i][2].record()
c = F.linear(a, b)
events[i][3].record()
flush_cache()
events[i][4].record()
c = F.linear(a, b)
events[i][5].record()
...
再次运行，结果为：
nsys结果为：
可以发现此时3个计算kernel的耗时基本一致，说明缓存的确影响了kernel的耗时。
除此之外，影响耗时的原因还可能是GPU频率的变化，可以通过以下代码进行设置频率：
DEVICE = os.environ.get("CUDA_VISIBLE_DEVICES")
CLOCK_SPEED = 1350 # Must choose a clock speed that's supported on your device.
def set_clock_speed():
"""
Set GPU clock speed to a specific value.
This doesn't guarantee a fixed value due to throttling, but can help reduce variance.
"""
process = subprocess.Popen("nvidia-smi", stdout=subprocess.PIPE, shell=True)
stdout, _ = process.communicate()
process = subprocess.run(f"nvidia-smi -pm ENABLED -i {DEVICE}", shell=True)
process = subprocess.run(f"nvidia-smi -lgc {CLOCK_SPEED} -i {DEVICE}", shell=True)
def reset_clock_speed():
"""
Reset GPU clock speed to default values.
"""
subprocess.run(f"nvidia-smi -pm ENABLED -i {DEVICE}", shell=True)
subprocess.run(f"nvidia-smi -rgc -i {DEVICE}", shell=True)
以上代码是将GPU频率锁定到指定值上，可自行尝试不同频率下的耗时情况。
结论
根据以上分析，同样的输入，测量kernel耗时不同的原因，有以下可能：
1. torch.cuda.event测量的时间包含了其他过程，不只是kernel本身
2. kernel运行时存在命中缓存，导致时间变短
3. GPU频率存在变化，当频率不同时，kernel的时间也会变化
一些建议
- 从以上示例来看，torch.cuda.event的测量并非与kernel对应，而是两个时间点之差。在使用时，要注意其他流程是否影响了统计的时间点。如果要观察kernel的耗时，建议直接使用nsys更为准确和直观。
参考
- https://blog.speechmatics.com/cuda-timings