C++ 代码执行时间随不应引入任何额外工作的小源更改而变化

C++ code execution time varies with small source change that shouldn't introduce any extra work

在对某些代码进行基准测试时,我发现即使是最无害的代码更改,其执行时间也会有所不同。

我试图将下面的代码归结为最小的测试用例,但它仍然相当冗长(为此我深表歉意)。几乎任何更改都会在很大程度上影响基准测试结果。

#include <string>
#include <vector>
#include <iostream>
#include <random>
#include <chrono>
#include <functional>

constexpr double usec_to_sec = 1000000.0;

// Simple convenience timer
class Timer
{
    std::chrono::high_resolution_clock::time_point start_time;
public:
    Timer() : start_time(std::chrono::high_resolution_clock::now()) { }
    int64_t operator()() const {
        return static_cast<int64_t>(
        std::chrono::duration_cast<std::chrono::microseconds>(
            std::chrono::high_resolution_clock::now()-start_time).count()
        );
    }
};

// Convenience random number generator
template <typename T>
class RandGen
{
    mutable std::default_random_engine generator;
    std::uniform_int_distribution<T> distribution;

    constexpr unsigned make_seed() const {
        return static_cast<unsigned>(std::chrono::system_clock::now().time_since_epoch().count());
    }
public:
    RandGen(T min, T max) : generator(make_seed()), distribution(min, max) { }
    T operator ()() { return distribution(generator); }
};

// Printer class
class Printer
{
    std::string filename;
    template <class S>    
    friend Printer &operator<<(Printer &, S &&s);
public:
    Printer(const char *filename) : filename(filename) {}
};

template <class S>
Printer &operator<<(Printer &pm, S &&s) {
    std::cout << s;
    return pm;
}

// +------------+
// | Main Stuff |
// +------------+
void runtest(size_t run_length)
{
    static RandGen<size_t> word_sz_generator(10, 20);
    static RandGen<int> rand_char_generator(0, 25);

    size_t total_char_count = 0;
    std::vector<std::string> word_list;
    word_list.reserve(run_length);

    Printer printer("benchmark.dat");
    printer << "Running test... ";

    Timer timer; // start timer
    for (auto i = 0; i < run_length; i++) {

        size_t word_sz = word_sz_generator();
        std::string word;
        for (auto sz = 0; sz < word_sz; sz++) {
            word.push_back(static_cast<char>(rand_char_generator())+'a');
        }
        word_list.emplace_back(std::move(word));
        total_char_count += word_sz;
    }
    int64_t execution_time_usec = timer(); // stop timer

    printer << /*run_length*/ word_list.size() << " words, and " 
            << total_char_count << " total characters, were built in "
            << execution_time_usec/usec_to_sec << " seconds.\n";
}

int main(int argc, char **argv)
{
    constexpr size_t iterations = 30;
    constexpr size_t run_length = 50000000;

    for (auto i = 0; i < iterations; i++)
        runtest(run_length);

    return EXIT_SUCCESS;
}

第1stclass,Timer,只是一个小小的方便class(为了简洁起见,故意不完善)用于计时代码。

我尝试不使用 2nd class RandGen(它只生成随机值),但是任何试图将其排除在测试之外的尝试代码使问题自动神奇地消失了。所以,我怀疑这个问题与它有关。但是我想不通。

3rd class Printer 对于这个问题似乎完全没有必要,但同样,包括它似乎加剧了这个问题。

所以,现在我们进入 main()(这只是 运行 测试)和 runtest()

runtest()很丑,请不要用"clean code"的眼光看。以任何方式更改它(例如将内部 for loop 移动到它自己的函数)都会导致基准测试结果发生变化。最简单也是最令人费解的例子是最后一行:

printer << /*run_length*/ word_list.size() << " words, and " 
        << total_char_count << " total characters, were built in "
        << execution_time_usec/usec_to_sec << " seconds.\n";

在上一行中,run_lengthword_list.size()是一样的。向量 word_list 的大小由 run_length 定义。但是,如果我按原样 运行 代码,我得到的平均执行时间是 9.8 秒 ,而如果我取消注释 run_length 并注释掉 word_list.size(),执行时间实际上 增加 到平均 10.6 秒 。我无法理解如此微不足道的代码更改如何在如此程度上影响整个程序的时间安排。

换句话说...

9.8秒:

printer << /*run_length*/ word_list.size() << " words, and " 
        << total_char_count << " total characters, were built in "
        << execution_time_usec/usec_to_sec << " seconds.\n";

10.6秒:

printer << run_length /*word_list.size()*/ << " words, and " 
        << total_char_count << " total characters, were built in "
        << execution_time_usec/usec_to_sec << " seconds.\n";

我多次重复注释和取消注释上述变量的练习,并重新运行设置基准。基准测试是可重复且一致的 - 即它们分别始终为 9.8 秒和 10.6 秒。

对于两种情况,代码输出如下所示:

Running test... 50000000 words, and 750000798 total characters, were built in 9.83379 seconds.
Running test... 50000000 words, and 749978210 total characters, were built in 9.84541 seconds.
Running test... 50000000 words, and 749996688 total characters, were built in 9.87418 seconds.
Running test... 50000000 words, and 749995415 total characters, were built in 9.85704 seconds.
Running test... 50000000 words, and 750017699 total characters, were built in 9.86186 seconds.
Running test... 50000000 words, and 749998680 total characters, were built in 9.83395 seconds.
...

Running test... 50000000 words, and 749988517 total characters, were built in 10.604 seconds.
Running test... 50000000 words, and 749958011 total characters, were built in 10.6283 seconds.
Running test... 50000000 words, and 749994387 total characters, were built in 10.6374 seconds.
Running test... 50000000 words, and 749995242 total characters, were built in 10.6445 seconds.
Running test... 50000000 words, and 749988379 total characters, were built in 10.6543 seconds.
Running test... 50000000 words, and 749969532 total characters, were built in 10.6722 seconds.
...

如能提供有关造成这种差异的原因的任何信息,我们将不胜感激。

备注:

  1. 即使从 Printer class 中删除未使用的 std::string filename 成员对象也会产生不同的基准测试结果 - 这样做会消除(或减少到微不足道的比例)两者之间的差异上面提供的基准。
  2. 这在使用 g++ 编译时似乎不是问题(在 Ubuntu 上)。虽然,我不能肯定地说;我对 Ubuntu 的测试是在同一台 Windows 机器上的 VM 中进行的,其中 VM 可能无法访问所有资源和处理器增强功能。
  3. 我正在使用 Visual Studio Community 2017(版本 15.7.4)
    • 编译器版本:19.14.26431
    • 所有测试和报告的结果都是 Release Build,64 位
  4. 系统:Win10,i7-6700K @ 4.00 GHz,32 GB RAM

我 运行 遇到了类似的情况,对代码的微小更改对 运行 时间产生了重大影响。将代码转换为汇编代码以控制代码位置后,我发现在 Intel 3770K 3.5ghz 处理器上存在显着差异,这取决于调用和紧密循环在内存中的位置。我发现最显着的差异是 36.5% 的时间差异,在我发布的这个问题中提到,最初是关于使用索引 b运行ching 进入代码与紧密循环。更 st运行ge 是它取决于汇编代码注释中指出的位置组合(可能是指令缓存中的冲突?),循环版本时间 运行ging 从1.465 秒到 2.000 秒,相同的代码,唯一的区别是用于将代码对齐到特定边界的函数之间的 nop。

Indexed branch overhead on X86 64 bit mode

我不知道其他处理器是否会因为代码的位置而出现如此大的性能差异。

您可能 运行正在使用某种代码对齐效果。大多数时候,现代 x86-64 CPUs 在对齐方面相当稳健,但对齐会影响分支预测器中的分支相互别名(如提到的@rcgldr),以及各种前端效果。

参见 https://agner.org/optimize/, and performance links in the x86 tag wiki。但老实说,我认为这里没有任何有用的解释,除了你发现你的循环对对齐效果很敏感,无论是来自前端还是来自分支预测。这意味着即使是相同的机器代码在您的主程序中以不同的对齐方式也可能具有不同的性能。

这是一个已知现象。关于 Code alignment in one object file is affecting the performance of a function in another object file has some general comments about how alignment can matter, and see also Why would introducing useless MOV instructions speed up a tight loop in x86_64 assembly? 的回答 某处有一篇文章介绍了如何以不同的顺序 linking 目标文件会影响性能(这是工具链的意外影响),但我找不到它。

您可以使用 HW 性能计数器来测量分支预测错误率,看看这是否可以解释为什么一个版本比另一个版本慢。 或者是否存在其他一些前端效应。

但遗憾的是,您无能为力;细微的源差异,如果它们完全影响 asm,将改变所有内容的对齐方式。

您有时可以通过用无分支代码替换分支来重新设计对分支预测不太敏感的东西。例如总是生成 16 个字节的随机字母,然后 t运行cate 到一个随机长度。 (复制时在大小上的一些分支可能是不可避免的,除非创建一个 16 字节的 std::string 然后 t运行 将其覆盖可以是无分支的。)

您可以使用 SIMD 加快速度,例如在 3.9GHz Skylake 上每 ~0.03 秒使用像 with an SSE2 or AVX2 xorshift+ to generate 16 bytes of random letters at a time. (efficiently getting a uniform 0..25 distribution with packed-byte operations may be tricky, but maybe the same technique as the 0..9 distribution I used to generate 1GiB of space-separated random ASCII digits 这样的矢量化 PRNG 会很有用。不过,它并不是完全均匀分布的,因为 65536 % 10 有余数(如 65536/25),但您可以改变质量与速度的权衡,仍然 运行 快。)


比较两个版本的编译器输出

runtest 函数中两个版本的内部循环的 asm 本质上是相同的,至少如果我们看到编译器 asm 输出 on the Godbolt compiler explorer匹配您实际从 MSVC 可执行文件中获得的内容。 (与 gcc/clang 不同,它的 asm 输出不一定被组装成一个工作目标文件。)如果你的真正的发布版本做了任何 link-time 优化可以内联一些库代码,它可能会使最终可执行文件中的不同优化选择。

我放入了一个 #ifdef,这样我就可以使用 -DUSE_RL 来获得两个以不同方式构建相同源的 MSVC 2017 输出,并将这些 asm 输出提供给差异窗格。 (差异窗格位于我 link 编辑的凌乱布局的底部;单击其上的全屏框即可显示 。)

整个函数的唯一区别是:

  • 一些指令的排序和寄存器选择,如函数顶部的 mov edx, DWORD PTR _tls_indexmov QWORD PTR run_length$GSCopy$[rbp-121], rcx,仅 运行 一次。 (但不是代码大小,因此它们以后不会影响对齐)。这对以后的代码应该没有影响,他们最终对架构状态进行了相同的更改,只是使用了一个不同的暂存 reg,它不再被使用。
  • 堆栈布局(局部变量相对于 RBP 的位置)。但是所有的偏移量都在+127以下,所以它们仍然可以使用[rbp + disp8]寻址模式。
  • 不同code-gen与实际源码差异:

          mov     rdx, QWORD PTR word_list$[rbp-113]
          sub     rdx, QWORD PTR word_list$[rbp-121]  ; word_list.size() = end - start 
          ...
          sar     rdx, 5               ; >> 5   arithmetic right shift
    

    对比

          mov     rdx, rsi             ; copy run_length from another register
    

    不,这些说明本身无法解释速度差异。它们每个时间间隔只有 运行 一次,在一些 I/O.

  • 之前
  • 一个额外的 npad 7 用于在函数底部附近的分支目标之前对齐(在 call _Xtime_get_ticks 之后),在上述代码差异之后。

有一大块 red/green 差异,但是 只有 来自不同的标签编号,函数开头的那三个指令除外。

但在 runtest 之前,word_list.size() 版本包含 ??$?6_K@@YAAEAVPrinter@@AEAV0@$QEA_K@Z PROC 函数的代码 ,该代码在使用的版本的任何地方都没有出现run_length。 (C++ 名称修改将类型转换为函数的 asm 名称中的古怪字符。)这正在为 class Printer.

做一些事情

您说从 Printer 中删除未使用的 std::string filename 消除了代码生成差异。好吧,那个功能可能会随着那个变化而消失。 IDK 为什么 MSVC 决定完全发出它,更不用说只在一个版本与另一个版本中发出了。

可能 g++ -O3 没有代码生成差异,这就是您看不到差异的原因。 (假设您的 VM 是硬件虚拟化,g++ 生成的机器代码仍然 运行 在 CPU 上本地运行。从 OS 获取新的内存页面可能需要稍长的时间VM,但在循环中花费的主要时间可能在这段代码中的 user-space 中。)


顺便说一句,gcc 警告

<source>:72:24: warning: comparison of integer expressions of different signedness: 'int' and 'size_t' {aka 'long unsigned int'} [-Wsign-compare]

     for (auto i = 0; i < run_length; i++) {
                      ~~^~~~~~~~~~~~

我没有仔细查看 asm 输出,看看这是否会导致 gcc 或 MSVC 的代码生成更糟糕,或者如果您传递大量输入,它是否会不安全。

我无法解释这一点,您可能需要与 Microsoft 联系才能揭开谜底。我拿了你的代码并编译了一个程序,它有两个版本的 runtest(),其中一个使用了这一行:

printer << /*run_length*/ word_list.size() << " words, and "

另一个使用

printer << run_length /* word_list.size() */ << " words, and "

郑重声明,我在 Visual Studio 2017 社区下构建 x64,我没有构建 x86 的能力,因为我删除了 x86 工具链和库(以及一些不必要的 ARM 东西) ) 获得 1 GB 左右的 space。

我的基准测试结果与你的一致,我 运行 一组较小的测试,但仍然足以始终如一地显示差异:

较慢的版本:

Running test... 50000000 words, and 749981638 total characters, were built in 16.3966 seconds.
Running test... 50000000 words, and 750037396 total characters, were built in 15.9712 seconds.
Running test... 50000000 words, and 749999562 total characters, were built in 16.0094 seconds.
Running test... 50000000 words, and 749990566 total characters, were built in 15.8863 seconds.
Running test... 50000000 words, and 749998381 total characters, were built in 15.8728 seconds.
Running test... 50000000 words, and 749997199 total characters, were built in 15.8799 seconds.

更快的版本:

Running test... 50000000 words, and 750000053 total characters, were built in 15.3437 seconds.
Running test... 50000000 words, and 750014937 total characters, were built in 15.4479 seconds.
Running test... 50000000 words, and 750054238 total characters, were built in 15.2631 seconds.
Running test... 50000000 words, and 750012691 total characters, were built in 15.5289 seconds.
Running test... 50000000 words, and 750013435 total characters, were built in 15.3742 seconds.
Running test... 50000000 words, and 749969960 total characters, were built in 15.3682 seconds.

也就是说,这两个例程生成的汇编器是不同的。不多,但还是有区别的。比较两者的大小,一个显着的区别是其中一个使用 r14 而另一个使用 rdi,此外还有一些其他细微差别。

这是一个奇怪的问题。 "word_list.size()" 版本在主外循环的迭代中有这个:

    for (auto i = 0; i < run_length; i++)
00007FF7C77D2CF9  inc         r13d
00007FF7C77D2CFC  mov         dword ptr [rbp-79h],r13d
00007FF7C77D2D00  movsxd      rax,r13d
00007FF7C77D2D03  cmp         rax,qword ptr [rbp-31h]
00007FF7C77D2D07  mov         r14d,0FFFFFFFFh
00007FF7C77D2D0D  lea         rcx,[word_sz_generator (07FF7C77D70F0h)]
00007FF7C77D2D14  jb          runtest+130h (07FF7C77D2B40h)
    int64_t execution_time_usec = timer(); // stop timer

而 "run_length" 版本是这样做的:

    for (auto i = 0; i < run_length; i++)
00007FF7C77D270B  inc         r13d
00007FF7C77D270E  mov         dword ptr [rbp-79h],r13d
00007FF7C77D2712  movsxd      rax,r13d
00007FF7C77D2715  mov         r14,qword ptr [rbp-31h]
00007FF7C77D2719  cmp         rax,r14
00007FF7C77D271C  mov         edi,0FFFFFFFFh
00007FF7C77D2721  lea         rcx,[word_sz_generator (07FF7C77D9820h)]
00007FF7C77D2728  jb          runtest2+130h (07FF7C77D2550h)
    int64_t execution_time_usec = timer(); // stop timer

请注意更快的版本如何在将 [rbp-31h]rax 进行比较之前将其显式加载到 r14 中。大概这样它以后可以使用它。然后它将 0FFFFFFFFh 放入 edi。同时,较慢的版本直接将 rax 与内存进行比较,然后将相同的常量加载到 r14d.

足以造成 3% 的性能差异吗?显然是这样。

TL;DR 差异就在那里。我完全无法解释它们。