c++ - 对两个连续测量进行基准测试时不一致

Question

我正在对一个函数进行基准测试，我发现有些迭代比其他迭代慢。

在一些测试之后，我尝试对两个连续的测量进行基准测试，但我仍然得到了一些奇怪的结果。

密码是on wandbox .

对我来说重要的部分是:

using clock = std::chrono::steady_clock;
// ...
for (int i = 0; i < statSize; i++)
{
    auto t1 = clock::now();
    auto t2 = clock::now();
}

循环被优化掉了 正如我们在 godbolt 上看到的那样.

call std::chrono::_V2::steady_clock::now()
mov r12, rax
call std::chrono::_V2::steady_clock::now()

代码编译:

g++  bench.cpp  -Wall  -Wextra -std=c++11 -O3

和gcc 版本 6.3.0 20170516 (Debian 6.3.0-18+deb9u1) Intel® Xeon® W-2195 Processor .

我是机器上唯一的用户，我尝试在高优先级和不高优先级(nice 或 chrt)下运行，结果是一样的。

我用 100 000 000 次迭代得到的结果是:

Y轴单位是纳秒，是直线的结果

std::chrono::duration_cast<std::chrono::nanoseconds>(t2 - t1).count()

这 4 行让我想到:No cache/L1/L2/L3 cache misses(即使“L3 cache misses”行看起来离 L2 行太近了)

我不确定为什么会出现缓存未命中，可能是结果的存储，但它不在测量代码中。

我已经尝试运行10000次循环为1500的程序，因为这个处理器的L1缓存是:

lscpu | grep L1 
L1d cache:             32K
L1i cache:             32K

1500*16 位 = 24000 位，小于 32K，因此不应该有缓存未命中。

结果:

我还有 4 条线(还有一些噪音)。

所以如果它真的是缓存未命中，我不知道为什么会发生。

我不知道它是否对你有用，但我运行:

sudo perf stat -e cache-misses,L1-dcache-load-misses,L1-dcache-load  ./a.out 1000

值为 1 000/10 000/100 000/1 000 000

我得到了所有 L1-dcache 命中率的 4.70% 到 4.30%，这对我来说相当不错。

所以问题是:

• 这些放缓的原因是什么？
• 当我不能为 No 操作设置固定时间时，如何生成函数的定性基准？

---

Ps : 如果我遗漏了有用的信息/标志，我不知道，尽管问!

---

如何复制:

1. 代码:

   #include <iostream>
   #include <chrono>
   #include <vector>
   
   int main(int argc, char **argv)
   {
       int statSize = 1000;
       using clock = std::chrono::steady_clock;
       if (argc == 2)
       {
           statSize = std::atoi(argv[1]);
       }
   
       std::vector<uint16_t> temps;
       temps.reserve(statSize);
       for (int i = 0; i < statSize; i++)
       {
   
           auto t1 = clock::now();
   
           auto t2 = clock::now();
   
           temps.push_back(
               std::chrono::duration_cast<std::chrono::nanoseconds>(t2 - t1).count());
       }
   
       for (auto t : temps)
           std::cout << (int)t << std::endl;
   
       return (0);
   }
   

2. 构建:

   g++  bench.cpp  -Wall  -Wextra -std=c++11 -O3
   

3. 生成输出(需要 sudo):

   在这种情况下，我运行程序 10 000 次。每次采取 100 项措施，我删除第一个，它总是慢 5 倍左右:

    for i in {1..10000} ; do sudo nice -n -17 ./a.out 100 | tail -n 99  >> fast_1_000_000_uint16_100 ; done
   

4. 生成图表:

   cat fast_1_000_000_uint16_100 | gnuplot -p -e "plot '<cat'"
   

5. 我机器上的结果:

---

Zulan 的回答和所有评论之后我在哪里

current_clocksource 在 tsc 上设置，在 dmesg 中没有看到开关，使用的命令:

dmesg -T | grep tsc

我use this script删除超线程 (HT) 然后

grep -c proc /proc/cpuinfo
=> 18

将最后的结果减1，得到最后一个可用的核心:

=> 17

编辑/etc/grub/default 并在 GRUB_CMDLINE_LINUX 中添加 isolcpus=(last result):

GRUB_CMDLINE_LINUX="isolcpus=17"

最后:

sudo update-grub
reboot 
// reexecute the script

现在我可以使用:

taskset -c 17 ./a.out XXXX

所以我运行 10 000 次 100 次迭代的循环。

for i in {1..10000} ; do sudo /usr/bin/time -v taskset -c 17 ./a.out 100  > ./core17/run_$i 2>&1 ; done

检查是否有任何非自愿上下文切换:

grep -L "Involuntary context switches: 0" result/* | wc -l
=> 0 

没有，很好。让我们绘制:

for i in {1..10000} ; do cat ./core17/run_$i | head -n 99 >> ./no_switch_taskset ; done
cat no_switch_taskset | gnuplot -p -e "plot '<cat'"

结果:

还有 22 个度量值大于 1000(当大多数值都在 20 左右时)我不明白。

下一步，待定

做这部分:

sudo nice -n -17 perf record...

祖兰人的回答

Answer 1

我无法用这些特定的簇线重现它，但这里有一些一般信息。

可能的原因

正如评论中所讨论的，正常空闲系统上的 nice 只是最大努力。你至少还有

1. 调度滴答计时器

2. 绑定(bind)特定代码的内核任务

3. 您的任务可能出于任意原因从一个核心迁移到另一个核心

您可以使用 isolcpus and taskset to get exclusive cores对于某些进程可以避免其中的一些，但我认为您无法真正摆脱所有内核任务。此外，使用 nohz=full to disable the scheduling tick .您还应该禁用超线程以从硬件线程获得对核心的独占访问权。

除了taskset，我绝对推荐用于任何性能测量，这些都是非常不寻常的测量。

测量而不是猜测

如果怀疑可能会发生什么，您通常可以设置测量来确认或反驳该假设。 perf 和跟踪点对此非常有用。例如，我们可以从查看调度事件和一些中断开始:

sudo nice -n -17 perf record -o perf.data -e sched:sched_switch -e irq:irq_handler_entry -e irq:softirq_entry ./a.out ...

perf script 现在会告诉您每次出现的情况。要将其与慢速迭代 相关联，您可以使用perf probe 和稍作修改的基准测试:

void __attribute__((optimize("O0"))) record_slow(int64_t count)
{
    (void)count;
}

...

    auto count = std::chrono::duration_cast<std::chrono::nanoseconds>(t2 - t1).count();
    if (count > 100) {
        record_slow(count);
    }
    temps.push_back(count);

然后用-g编译

sudo perf probe -x ./a.out record_slow count

然后将-e probe_a:record_slow 添加到对perf record 的调用中。现在，如果幸运的话，您会发现一些关闭事件，例如:

 a.out 14888 [005] 51213.829062:    irq:softirq_entry: vec=1 [action=TIMER]
 a.out 14888 [005] 51213.829068:  probe_a:record_slow: (559354aec479) count=9029

请注意:虽然这些信息可能会解释您的一些观察结果，但您进入了一个充满更多令人费解的问题和怪事的世界。此外，虽然 perf 的开销非常低，但您测量的内容可能会有一些扰动。

我们的基准测试是什么？

首先，你需要明确你实际测量的是什么:执行std::chrono::steady_clock::now()的时间。这样做实际上很好，至少可以计算出这种测量开销以及时钟精度。

这实际上是一个棘手的问题。此函数的成本(下面是 clock_gettime)取决于您当前的时钟源¹。如果那是 tsc，那你没问题 - hpet 慢得多。 Linux 可能会在运行期间从 tsc 悄悄地² 切换到 hpet。

如何获得稳定的结果？

有时您可能需要在极端隔离的情况下进行基准测试，但即使对于非常低级别的微架构基准测试，通常也没有必要这样做。相反，您可以使用统计效应:重复测量。使用适当的方法(均值、分位数)，有时您可能希望排除异常值。

如果测量内核没有明显长于定时器精度，您将不得不重复内核并在外部进行测量以获得吞吐量而不是延迟，这可能会有所不同。

是的 - 正确的基准测试非常复杂，您需要考虑很多方面，尤其是当您接近硬件并且您的内核时间变得非常短时。幸运的是有一些帮助，例如 Google's benchmark library在进行正确的重复次数以及实验因素方面提供了很多帮助。

¹ /sys/devices/system/clocksource/clocksource0/current_clocksource

² 实际上它在 dmesg 中就像这样

clocksource: timekeeping watchdog on CPU: Marking clocksource 'tsc' as unstable because the skew is too large: