c++ - 同一个程序运行时间差异很大，有时达到1000+us

Question

#include <stdio.h>
#include <stdarg.h>
#include <sys/time.h>

char kBuff[1024];
const char* kMsg = "0123456789 abcdefghizklmnopqrstuvwxyz ABCDEFGHIJKLMNOPQRSTUVWXYZ";
const long kThreshold = 100; //us

void func(const char* fmt, ...) {  
  struct timeval start, end;
  gettimeofday(&start, NULL);

  va_list ap;
  va_start (ap, fmt);
  vsnprintf(kBuff, sizeof(kBuff) - 1, fmt, ap);
  va_end (ap);

  gettimeofday(&end, NULL);

  long during = (end.tv_sec - start.tv_sec) * 1000 * 1000 + (end.tv_usec - start.tv_usec);
  if (during > kThreshold)
    printf("%ld, ", during);
}

int main() {
  long index = 0;
  for(int i = 0; i < 1000000; i++) {
    func("Index:%8ld Msg:%s", index++, kMsg);
  }
}

我把一段很简单的代码运行了10,000,000次，有时具体一段代码的运行时间相差很大，有时达到1000+us。 结果如下:

105, 106, 135, 115, 121, 664, 135, 1024, 165, 130,

程序运行在Windows-10上的Ubuntu-18.04虚拟机

g++ -ggdb -O2 test.cpp

gettimeofday(&start, NULL);

va_list ap;
va_start (ap, fmt);
vsnprintf(kBuff, sizeof(kBuff) - 1, fmt, ap);
va_end (ap);

gettimeofday(&end, NULL);

上面的代码不落入内核，不等待I/O，不等待锁，为什么运行时间可以达到1000us？

我猜测的一个原因是由于操作系统的调度。但我如何证明这一点？

如果是这个原因，那我该如何准确的衡量一个程序的运行时间呢？

Answer 1

简单地使用挂钟时间来衡量性能通常是不够的，原因如下

1. 操作系统可能会在 CPU 上安排其他进程(如您提到的)
2. 由于可能的编译器重新排序，您可能无法衡量您实际尝试衡量的内容(Enforcing statement order in C++ 对此进行了详细讨论)
3. 测量时间的例程(在您的情况下为 gettimeofday)本身有开销，这可能包含在您的测量中，从而引入噪音

有类似 perf tool 的工具使用 performance counters和 tracepoints在没有这些问题的情况下分析性能。

我找到了 https://www.youtube.com/watch?v=nXaxk27zwlk学习如何进行基准测试的一个很好的起点。它讨论了 google benchmark 的用法。和 perf 都对衡量性能很有用。

话虽如此，使用这些工具并不意味着您的测量结果不会出现差异。实时性能受多种因素影响，如缓存、changing clock frequencies ，页面错误等。除非您在实时系统上工作，否则尾部延迟很少成为问题。