linux - 为什么 clock_gettime(CLOCK_REALTIME, ..) 上的调用延迟变化如此之大？

Question

我正在尝试计算 clock_gettime(CLOCK_REALTIME,...) 调用所需的时间。 “回到过去”我曾经在循环的顶部调用它一次，因为这是一个相当昂贵的调用。但现在，我希望通过 vDSO 和一些时钟改进，它可能不会那么慢。

我写了一些测试代码，使用 __rdtscp 对 clock_gettime 的重复调用进行计时(rdtscp 调用围绕一个调用 clock_gettime 并将结果加在一起，这样编译器就不会优化太多)。

如果我快速连续调用 clock_gettime()，时间长度会从大约 45k 个时钟周期减少到 500 个周期。我认为其中一些可能导致第一次调用必须加载 vDSO 代码(对我来说仍然没有完全意义)，但是如何需要几次调用才能获得 500 我根本无法解释，而且这种行为似乎无论我如何测试它都保持不变:

42467
1114
1077
496
455

但是，如果我在调用 clock_gettime 之间休眠(一秒或十秒，无关紧要)，它只会达到大约 4.7k 周期的稳定状态:

此处为 10 秒 sleep :

28293
1093
4729
4756
4736

此处 1 秒 sleep :

61578
855
4753
4741
5645
4753
4732

缓存行为似乎无法描述这一点(在桌面系统上什么都不做)。我应该为调用 clock_gettime 预算多少？为什么调用会越来越快？为什么睡一小会儿时间如此重要？

tl;dr 我试图了解调用 clock_gettime(CLOCK_REALTIME,...) 所花费的时间 不明白为什么它在调用时运行得更快快速连续，而不是通话之间的一秒钟。

更新:这是 proc 0 上的 cpuinfo

processor   : 0
vendor_id   : GenuineIntel
cpu family  : 6
model       : 158
model name  : Intel(R) Core(TM) i7-7700HQ CPU @ 2.80GHz
stepping    : 9
microcode   : 0x84
cpu MHz     : 2800.000
cache size  : 6144 KB
physical id : 0
siblings    : 8
core id     : 0
cpu cores   : 4
apicid      : 0
initial apicid  : 0
fpu     : yes
fpu_exception   : yes
cpuid level : 22
wp      : yes
flags       : fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat pse36 clflush dts acpi mmx fxsr sse sse2 ss ht tm pbe syscall nx pdpe1gb rdtscp lm constant_tsc art arch_perfmon pebs bts rep_good nopl xtopology nonstop_tsc cpuid aperfmperf tsc_known_freq pni pclmulqdq dtes64 monitor ds_cpl vmx est tm2 ssse3 sdbg fma cx16 xtpr pdcm pcid sse4_1 sse4_2 x2apic movbe popcnt tsc_deadline_timer aes xsave avx f16c rdrand lahf_lm abm 3dnowprefetch cpuid_fault epb intel_pt tpr_shadow vnmi flexpriority ept vpid fsgsbase tsc_adjust bmi1 avx2 smep bmi2 erms invpcid mpx rdseed adx smap clflushopt xsaveopt xsavec xgetbv1 xsaves dtherm ida arat pln pts hwp hwp_notify hwp_act_window hwp_epp
bugs        :
bogomips    : 5616.00
clflush size    : 64
cache_alignment : 64
address sizes   : 39 bits physical, 48 bits virtual
power management:

这是重新创建的测试代码:

#include <time.h>
#include <unistd.h>
#include <stdio.h>
#include <stdlib.h>
#include <x86intrin.h>

// compiled gcc -Wall -O3 -o clockt clockt.cpp
// called glockt sleeptime trials loops

unsigned long long now() {
    struct timespec s;
    clock_gettime(CLOCK_REALTIME, &s);
    return (s.tv_sec * 1000000000ull) + s.tv_nsec;
}

int main(int argc, char **argv) {
    int sleeptime = atoi(argv[1]);
    int trials = atoi(argv[2]);
    int loops = atoi(argv[3]);

    unsigned long long x, y, n = 0;
    unsigned int d;


    x = __rdtscp(&d);
    n = now();
    asm volatile("": "+r" (n));
    y = __rdtscp(&d);

    printf("init run %lld\n", (y-x));

    for(int t = 0; t < trials; ++t) {
        if(sleeptime > 0) sleep(sleeptime);
        x = __rdtscp(&d);
        for(int l = 0; l < loops; ++l) {
            n = now();
            asm volatile("": "+r" (n));
        }
        y = __rdtscp(&d);
        printf("trial %d took %lld\n", t, (y-x));
    }

    exit(0);
}

Answer 1

第一次调用 clock_gettime 时，页面错误发生在包含该函数指令的页面上。在我的系统上，这是一个软页面错误，需要几千个周期来处理(最多 10,000 个周期)。我的 CPU 运行在 3.4GHz。我认为您的 CPU 以低得多的频率运行，因此处理系统上的页面错误将花费更多时间。但这里的要点是，第一次调用 clock_gettime 将比以后的调用花费更多的时间，这就是您所观察到的情况。

您的代码表现出的第二个主要影响是指令高速缓存未命中导致的严重停顿。看起来您只调用了两个函数，即 now 和 printf，但这些函数调用其他函数并且它们都在 L1 指令缓存中竞争。总的来说，这取决于所有这些函数在物理地址空间中的对齐方式。当休眠时间为零秒时，由于指令高速缓存未命中而导致的停顿时间实际上相对较小(您可以使用 ICACHE.IFETCH_STALL 性能计数器进行测量)。然而，当 sleep 时间大于零秒时，这个停顿时间会变得明显更长，因为操作系统将安排一些其他线程在同一内核上运行，并且该线程将使用不同的指令和数据。这解释了为什么当你 sleep 时，clock_gettime 需要更多的时间来执行。

现在关于第二次和以后的测量。来自问题:

42467
1114
1077
496
455

我在我的系统上观察到，第二次测量不一定比后来的测量大。我相信这在您的系统上也是如此。事实上，你睡10秒或1秒似乎就是这样。在外层循环中，now 和printf 这两个函数包含数千条动态指令，它们还访问 L1 数据缓存。您在第二次和以后的测量之间看到的可变性是可重现的。所以它是函数本身固有的。请注意，rdtscp 指令本身的执行时间可能会相差 4 个周期。另见 this .

在实践中，clock_gettime 在所需精度最多为一百万个周期时很有用。否则，它可能会产生误导。