C 基准测试首轮执行次数异常偏低,可能是什么原因?
结论
这组数据表明,异常出现在正式测量的首轮。time(NULL) 只有秒级精度,确实不适合精确测量 5 秒区间,但通常不足以解释执行次数从约 7800 次骤降到 116 次。更可能是首轮执行时出现了额外耗时,或 benchmark_main() 在这一轮走了不同的代码路径。要确认原因,需要记录每次调用情况和每轮的实际耗时。
先检查计时方式
time(NULL) 返回的时间精度为秒。循环根据整数秒差值判断何时结束,因此实际测量时长会受计时边界影响,偏差不到一秒。各轮的测量区间可能因此不完全一致,但这本身不能解释首轮的低值。
可以改用 clock_gettime(CLOCK_MONOTONIC, ...) 测量单调经过时间,避免系统日历时间调整对计时的影响:
#include <time.h>
static double elapsed_seconds(struct timespec start, struct timespec end) {
return (double)(end.tv_sec - start.tv_sec) +
(double)(end.tv_nsec - start.tv_nsec) / 1e9;
}
for (int i = 0; i < RUNS; i++) {
struct timespec start, now;
int nb_r = 0;
if (clock_gettime(CLOCK_MONOTONIC, &start) != 0) {
perror("clock_gettime");
return 1;
}
do {
benchmark_main();
nb_r++;
if (clock_gettime(CLOCK_MONOTONIC, &now) != 0) {
perror("clock_gettime");
return 1;
}
} while (elapsed_seconds(start, now) < SECONDS_TO_RUN);
result_arr[i] = nb_r;
}
这段写法会把一次 benchmark_main() 的执行时间计入测量时长。如果希望每次调用开始前都检查时间,可以把时间检查移到调用之前。两种写法的计时边界略有不同,所有轮次应使用同一种方式。
定位首轮额外耗时
在每轮开始和结束时记录单调时钟时间,并暂时记录每次 benchmark_main() 的耗时或返回值。这样可以判断是整轮被拖慢,还是某次调用特别慢。查看日志时,留意首轮是否出现长时间停顿、初始化、缺页、磁盘或网络访问,也要检查是否有其他进程争用 CPU。
还要确认 warmup_run 是否在同一进程、相同状态下执行了相同的代码路径。即使预热次数接近,如果进程、输入或初始化状态不同,也不能保证正式测量的首次调用已经预热。
修正结果文件路径的 snprintf 调用
给出的代码中,snprintf 的参数顺序不符合函数签名。应先传入缓冲区大小,再传入格式字符串:
snprintf(result_file, sizeof(result_file),
"../logs/%s/%s/%s.txt", machine, profile, bin);
当前写法会导致编译诊断或未定义行为,需要修复。不过,这段代码位于测量循环之后。按贴出的控制流,它不能直接解释已经统计出的首轮执行次数异常。也可以检查返回值,确认路径没有被截断。
注意事项
目前忽略了 benchmark_main() 的返回值。如果返回值能表示执行失败,应记录并处理;否则,执行次数只表示函数被调用的次数,不代表每次都成功完成了预期工作。先使用单调时钟并增加诊断日志,复现几次,再根据首轮耗时和调用轨迹判断是否存在一次性初始化或系统资源争用。
备注:内容仅供参考。
