简单循环中的大量时间损失

Question

我有一个非常简单的程序来测量函数所花费的时间。

#include <iostream>
#include <vector>
#include <chrono>
struct Foo
{
void addSample(uint64_t s)
{
}
};
void test(const std::vector<uint64_t>& samples)
{
uint32_t onlyCallTime = 0;
uint32_t loopOnlyTime = 0;
Foo stats;
std::chrono::high_resolution_clock::time_point callStart,callEnd;
auto start = callStart = callEnd = std::chrono::high_resolution_clock::now();
for(auto &s : samples)
{
callStart = std::chrono::high_resolution_clock::now();
loopOnlyTime += std::chrono::duration_cast<std::chrono::microseconds>(callStart-callEnd).count();
stats.addSample(s);
callEnd = std::chrono::high_resolution_clock::now();
onlyCallTime += std::chrono::duration_cast<std::chrono::microseconds>(callEnd-callStart).count();
}
auto end = std::chrono::high_resolution_clock::now();
std::cout << "overall duration: " << std::chrono::duration_cast<std::chrono::microseconds>(end-start).count() << std::endl;
std::cout << "only call duration: " << onlyCallTime << std::endl;
std::cout << "only loop duration: " << loopOnlyTime << std::endl;
}
int main()
{
std::vector<uint64_t> dataSetDecreasing;
for(uint32_t i = 0; i < 1000000; ++i)
dataSetDecreasing.push_back(1000000-i);
test(dataSetDecreasing);
}

输出确实令人困惑。以下是一些例子：

overall duration: 56047
only call duration: 195
only loop duration: 285

overall duration: 40984
only call duration: 177
only loop duration: 243

overall duration: 47328
only call duration: 187
only loop duration: 177

我认为callEnd-callStart捕获了对addSample+duration_cast的调用
callStart-callEnd捕获其他所有内容，因此循环初始化、迭代、条件和第二个duration_cast。我错过了什么？其他约40000微秒将何去何从？

使用g++ -Wall -Wextra -std=c++17 -O3编译
g++ (GCC) 10.2.1 20200723 (Red Hat 10.2.1-1)
我的操作系统是Fedora 32版(三十二(

Answer 1

1000 000次迭代大约花费了50000微秒。平均每次迭代远低于1μs，std::chrono::duration_cast<std::chrono::microseconds>将在小于1μs的任何时间四舍五入到0。这意味着您的循环只计算由于某些原因(可能是调度、页面错误、缓存(而花费的迭代时间远远超过平均值。

由于每次测量都有一个基本误差，与测量的持续时间无关(加上其他误差(，因此进行许多小的测量并将其相加将远不如测量一次整个持续时间精确。