由于分析部分之外的代码，使用 clock_gettime() 的不合理时间测量
Unjustified time measurements with clock_gettime() due to code outside the profiled section
我正在使用下面的 C 程序（用 gcc 编译）来测量给定代码段的计算时间。
问题是，当 uleep() 函数在 外部 正在分析的代码段中使用时，在 elapsed_time.
中获得不同的测量值
#include <unistd.h>
#include <stdio.h>
#include <time.h>
int main()
{
int f = 0;
while (f < 10)
{
double sum = 1.0;
struct timespec t0, t1;
clock_gettime(CLOCK_MONOTONIC, &t0);
// CODE SECTION BEING PROFILED
for (unsigned int i = 0; i < 5e6; i++)
sum += 0.001;
// END OF CODE SECTION BEING PROFILED
clock_gettime(CLOCK_MONOTONIC, &t1);
double elapsed_time = t1.tv_sec - t0.tv_sec;
elapsed_time += (t1.tv_nsec - t0.tv_nsec) * 1e-9;
printf("%.2f ms\n", elapsed_time*1000 );
f++;
// Sleep causing fake clock_gettime measurements?
usleep(50000);
}
return 0;
}
下面我把评论uleep(50000)时程序的结果贴出来：
13.83 毫秒
14.30 毫秒
14.41 毫秒
13.77 毫秒
13.85 毫秒
13.88 毫秒
14.55 毫秒
13.28 毫秒
13.70 毫秒
13.56 毫秒
现在，出现 uleep(50000) 时的结果：
15.37 毫秒
14.16 毫秒
36.43 毫秒
39.39 毫秒
36.38 毫秒
36.27 毫秒
34.14 毫秒
38.52 毫秒
38.18 毫秒
37.53 毫秒
我尝试在 clock_gettime() 中使用不同的时钟测量时间，并且还使用 C++ std::chrono::high_resolution_clock。但是，所有情况下的结果都是相似的。
此外，我尝试了不同的 gcc 标志，例如O2。在这种情况下，虽然获得的时间要小得多，但仍然存在 usleep() 时的一些测量值比不存在 usleep() 时高 ~3x。
我发现 usleep() 中使用的微秒数会影响最终的测量时间，例如用 10000us 我得到：
13.75 毫秒
13.54 毫秒
13.34 毫秒
14.15 毫秒
13.12 毫秒
12.79 毫秒
28.72 毫秒
25.84 毫秒
26.18 毫秒
24.53 毫秒
在所有这些测试之后，我无法找到导致此程序中这些“虚假”时间测量的原因。如果有人能阐明这个问题，我将不胜感激。
提前致谢！
编辑：
经过进一步测试后，我意识到同样的问题是由 printf() 引起的（请参阅下面的代码）。
#include <unistd.h>
#include <stdio.h>
#include <time.h>
int main()
{
double total_time = 0.0;
int f = 0;
while (f < 1000)
{
double sum = 1.0;
struct timespec t0, t1;
clock_gettime(CLOCK_MONOTONIC, &t0);
// Code section being profiled
for (unsigned int i = 0; i < 5e6; i++)
sum += 0.001;
// End of Code section being profiled
clock_gettime(CLOCK_MONOTONIC, &t1);
double elapsed_time = t1.tv_sec - t0.tv_sec;
elapsed_time += (t1.tv_nsec - t0.tv_nsec) * 1e-9;
total_time += elapsed_time;
f++;
// Sleep/printf causing fake clock_gettime measurements?
printf("%.2f ms\n", elapsed_time*1000 );
// usleep(10000);
}
printf("TOTAL TIME: %.2f ms\n", total_time*1000 );
return 0;
}
结果
当我运行这段代码用g++ -gf编译时，我得到的总时间是：
- ~13071.42 ms 当行
printf("%.2f ms\n", elapsed_time*1000 ); 存在时（注意该行再次位于正在分析的部分之外）。
- ~12712.22 ms，当该行被注释时。
如果程序使用优化编译（g++ -O2），我获得的总时间为：
- ~3145.27 ms 当
printf() 存在时。
- ~2741.45 ms 当
printf() 不存在时。
与 usleep() 相比，printf() 的测量时间增加幅度较小。因此， usleep() 似乎并不是导致此问题的唯一功能......
无论如何，对于放置在正在分析的代码部分之外的代码，测量的时间不应该受到影响......我错过了什么吗？
编辑 2：
我试过的不同时钟是：
CLOCK_MONOTONIC_RAW、CLOCK_PROCESS_CPUTIME_ID 和 CLOCK_REALTIME。他们都提供相同的行为。
此外，我验证了 clock_gettime() 的 return 值以丢弃失败。
看来您是 CPU frequency scaling 的受害者。
CPU频率缩放
您的 CPU 缩放驱动程序根据各种因素调节 CPU 频率，但重要的是根据当前 CPU 负载。 Linux 内核有各种可用的驱动程序，以及不同的缩放调节器。每个驱动程序都可以支持一组特定的缩放调控器，并且根据当前活动的调控器表现不同。
例如，我的笔记本电脑上的默认驱动程序是 intel_pstate，可用的调速器 powersave 和 performance。如果我将驱动程序更改为 acpi-cpufreq，我也会得到 ondemand、userspace 和 conservative。
不同调速器之间的主要区别从它们的名称就可以看出：powersave 调速器会尝试将 CPU 保持在较低的频率以节省电力，而 performance 调速器将尝试将 CPU 保持在高频率以使事情进行得更快。
在某些情况下，performance 调控器只是将 CPU 频率固定为最大可用频率（对我来说，这就是 intel_pstate 驱动程序所发生的情况）。在其他情况下，它只会尝试保持它 "high"，但它仍然会进行调整（对我来说，这就是 acpi-cpufreq 驱动程序所发生的情况）。
在任何情况下，动态 调节 CPU 频率的缩放驱动程序和调速器的组合，将考虑 CPU 负载，以便尽可能即时调整频率。这可能发生在通过系统调用输入内核代码时，或者当内核本身 运行 调度程序重新调度当前 运行ning 进程时的调度滴答上。
发生了什么事？
您很可能拥有动态设置 CPU 频率的缩放驱动程序和调控器的组合。
当你的代码运行s 没有调用usleep()时，CPU负载很重，频率基本稳定。但是，如果您的代码调用 usleep()，CPU 负载会显着降低，并且缩放驱动程序会降低 CPU 频率。当进程在睡眠后被内核唤醒时，频率要低得多，并且缩放驱动程序需要一些时间才能意识到它需要提升。如果您保持定期休眠，驱动程序可能永远没有足够的时间重新调整频率，代码只会 运行 变慢。
这也适用于 printf()，它需要进行 write() 系统调用才能打印文本，并且几乎适用于任何其他系统调用。在用户 space 和内核 space 之间切换会减慢进程，从而使缩放驱动程序降低频率。对于像 clock_gettime() 这样的某些系统调用，这不会发生，它在用户 space 中优化为 运行，并且不需要上下文切换。
这是一个例子，在我的机器上，有一个动态调节器（例如 ondemand）：
您可以清楚地看到 CPU 频率在第一个 运行 期间卡在最大值（ 没有 usleep()），并且然后在第二个运行（和 usleep()）期间上下波动，没有足够的时间稳定下来。事实上，您可以注意到测试 #2 的 avg 时间几乎是测试 #1 的 3 倍。我机器上的 acpi-cpufreq 和调控器 performance 也会发生这种情况。
解决方案
如果您能够设置保持固定 CPU 频率的不同缩放比例 driver/governor 组合，您会发现两个版本的代码在时间上没有差异。
这是另一个例子，在我的机器上，使用静态 CPU 频率（例如，使用 userspace 调速器并手动设置固定速度）：
如您所见，两个测试 运行 几乎同时进行。
如果您无法设置不同的缩放调控器，请尝试更改内核的缩放驱动程序。如果 运行ning Debian 或 Ubuntu，您可能有不同缩放驱动程序的可加载模块。
您可以通过查看当前的内核配置来查看适用于您的内核的可用扩展驱动程序和调控器：
cat /boot/config-$(uname -r) | grep FREQ
例如我可以看到：
...
CONFIG_X86_PCC_CPUFREQ=m
CONFIG_X86_ACPI_CPUFREQ=m
...
其中 m 表示 "available as a module"（可使用 modprobe 加载），y 表示 "built-in"。
然后你可以，例如，尝试做：
# Load acpi-cpufreq since we have CONFIG_X86_ACPI_CPUFREQ=m
sudo modprobe acpi_cpufreq
# Switch driver
echo acpi-cpufreq | sudo tee /sys/devices/system/cpu/cpu*/cpufreq/scaling_driver
# Check available governors for the driver
cat /sys/devices/system/cpu/cpu*/cpufreq/scaling_available_governors
测试代码
这是用于上述 GIF 的基准测试代码：
#define _GNU_SOURCE
#include <unistd.h>
#include <stdio.h>
#include <time.h>
#include <math.h>
#include <sched.h>
#include <sys/types.h>
/**
* Marco Bonelli - 2020-03-02
*
*
* Test the effect of different scaling governors on CPU frequency and
* performance under:
*
* 1) Continuous heavy load.
* 2) Intermittent and short heavy load.
*
* gcc -O3 scaling_governor_test.c -o test
* ./test [N_RUNS] [N_CYCLES_PER_RUN] [TEST2_DELAY_US]
*/
#define DEFAULT_RUNS 1000
#define DEFAULT_CYCLES 1000 * 1000
#define DEFAULT_DELAY 100 * 1000
// Don't optimize this as GCC would basically trash the whole function.
#pragma GCC push_options
#pragma GCC optimize("O0")
void __attribute__ ((noinline)) func(unsigned n) {
double sum = 1.0;
for (unsigned i = 0; i < n; i++)
sum += 0.001;
}
#pragma GCC pop_options
void warmup(unsigned runs, unsigned cycles) {
for (unsigned n = 1; n <= runs; n++)
func(cycles);
}
double bench(unsigned n) {
struct timespec t0, t1;
clock_gettime(CLOCK_PROCESS_CPUTIME_ID, &t0);
func(n);
clock_gettime(CLOCK_PROCESS_CPUTIME_ID, &t1);
return (t1.tv_sec - t0.tv_sec)*1000.0L + (t1.tv_nsec - t0.tv_nsec)/1000.0L/1000.0L;
}
void setup_affinity(void) {
cpu_set_t set;
CPU_ZERO(&set);
CPU_SET(0, &set);
if (geteuid() == 0) {
if (sched_setaffinity(0, sizeof(set), &set) == 0)
puts("Affinity set to CPU #0.");
else
perror("sched_setaffinity");
} else {
puts("Running as normal user, run as root to set CPU affinity.");
}
}
int main(int argc, char **argv) {
unsigned runs, cycles, delay;
double cur, tot1, tot2, min, max, avg;
if (argc < 2 || sscanf(argv[1], "%i", &runs) != 1 || runs < 1)
runs = DEFAULT_RUNS;
if (argc < 3 || sscanf(argv[2], "%i", &cycles) != 1 || cycles < 1)
cycles = DEFAULT_CYCLES;
if (argc < 4 || sscanf(argv[3], "%i", &delay) != 1 || delay < 1)
delay = DEFAULT_DELAY;
setup_affinity();
printf("Benchmarking %u runs of %u cycles each.\n", runs, cycles);
printf("Test #1 will proceed normally.\nTest #2 will usleep(%u) before each run.\n", delay);
fputs("Warming up... ", stdout);
fflush(stdout);
warmup(10, cycles);
puts("done.\n---");
tot1 = 0;
min = INFINITY;
max = -INFINITY;
for (unsigned n = 1; n <= runs; n++) {
cur = bench(cycles);
tot1 += cur;
avg = tot1 / n;
if (cur < min) min = cur;
if (cur > max) max = cur;
printf("\rTest #1: tot %-9.3f avg %-7.3f min %-7.3f max %-7.3f [ms]", tot1, avg, min, max);
fflush(stdout);
}
putchar('\n');
tot2 = 0;
min = INFINITY;
max = -INFINITY;
for (unsigned n = 1; n <= runs; n++) {
usleep(delay);
cur = bench(cycles);
tot2 += cur;
avg = tot2 / n;
if (cur < min) min = cur;
if (cur > max) max = cur;
printf("\rTest #2: tot %-9.3f avg %-7.3f min %-7.3f max %-7.3f [ms]", tot2, avg, min, max);
fflush(stdout);
}
puts("\n---");
if (tot1 < tot2)
printf("Test #2 ran ~%.3fx slower than Test #1.\n", tot2/tot1);
else if (tot1 > tot2)
printf("Test #1 ran ~%.3fx slower than Test #2.\n", tot1/tot2);
else
puts("Reality is a simulation.");
if (avg < 0.5)
puts("Such low average times are not a good indicator. You should re-run the rest with different parameters.");
return 0;
}
我正在使用下面的 C 程序（用 gcc 编译）来测量给定代码段的计算时间。
问题是，当 uleep() 函数在 外部 正在分析的代码段中使用时，在 elapsed_time.
#include <unistd.h>
#include <stdio.h>
#include <time.h>
int main()
{
int f = 0;
while (f < 10)
{
double sum = 1.0;
struct timespec t0, t1;
clock_gettime(CLOCK_MONOTONIC, &t0);
// CODE SECTION BEING PROFILED
for (unsigned int i = 0; i < 5e6; i++)
sum += 0.001;
// END OF CODE SECTION BEING PROFILED
clock_gettime(CLOCK_MONOTONIC, &t1);
double elapsed_time = t1.tv_sec - t0.tv_sec;
elapsed_time += (t1.tv_nsec - t0.tv_nsec) * 1e-9;
printf("%.2f ms\n", elapsed_time*1000 );
f++;
// Sleep causing fake clock_gettime measurements?
usleep(50000);
}
return 0;
}
下面我把评论uleep(50000)时程序的结果贴出来：
13.83 毫秒 14.30 毫秒 14.41 毫秒 13.77 毫秒 13.85 毫秒 13.88 毫秒 14.55 毫秒 13.28 毫秒 13.70 毫秒 13.56 毫秒
现在，出现 uleep(50000) 时的结果：
15.37 毫秒 14.16 毫秒 36.43 毫秒 39.39 毫秒 36.38 毫秒 36.27 毫秒 34.14 毫秒 38.52 毫秒 38.18 毫秒 37.53 毫秒
我尝试在 clock_gettime() 中使用不同的时钟测量时间，并且还使用 C++ std::chrono::high_resolution_clock。但是，所有情况下的结果都是相似的。
此外，我尝试了不同的 gcc 标志，例如O2。在这种情况下，虽然获得的时间要小得多，但仍然存在 usleep() 时的一些测量值比不存在 usleep() 时高 ~3x。
我发现 usleep() 中使用的微秒数会影响最终的测量时间，例如用 10000us 我得到：
13.75 毫秒 13.54 毫秒 13.34 毫秒 14.15 毫秒 13.12 毫秒 12.79 毫秒 28.72 毫秒 25.84 毫秒 26.18 毫秒 24.53 毫秒
在所有这些测试之后，我无法找到导致此程序中这些“虚假”时间测量的原因。如果有人能阐明这个问题，我将不胜感激。
提前致谢！
编辑：
经过进一步测试后，我意识到同样的问题是由 printf() 引起的（请参阅下面的代码）。
#include <unistd.h>
#include <stdio.h>
#include <time.h>
int main()
{
double total_time = 0.0;
int f = 0;
while (f < 1000)
{
double sum = 1.0;
struct timespec t0, t1;
clock_gettime(CLOCK_MONOTONIC, &t0);
// Code section being profiled
for (unsigned int i = 0; i < 5e6; i++)
sum += 0.001;
// End of Code section being profiled
clock_gettime(CLOCK_MONOTONIC, &t1);
double elapsed_time = t1.tv_sec - t0.tv_sec;
elapsed_time += (t1.tv_nsec - t0.tv_nsec) * 1e-9;
total_time += elapsed_time;
f++;
// Sleep/printf causing fake clock_gettime measurements?
printf("%.2f ms\n", elapsed_time*1000 );
// usleep(10000);
}
printf("TOTAL TIME: %.2f ms\n", total_time*1000 );
return 0;
}
结果
当我运行这段代码用g++ -gf编译时，我得到的总时间是：
- ~13071.42 ms 当行
printf("%.2f ms\n", elapsed_time*1000 );存在时（注意该行再次位于正在分析的部分之外）。 - ~12712.22 ms，当该行被注释时。
如果程序使用优化编译（g++ -O2），我获得的总时间为：
- ~3145.27 ms 当
printf()存在时。 - ~2741.45 ms 当
printf()不存在时。
与 usleep() 相比，printf() 的测量时间增加幅度较小。因此， usleep() 似乎并不是导致此问题的唯一功能......
无论如何，对于放置在正在分析的代码部分之外的代码，测量的时间不应该受到影响......我错过了什么吗？
编辑 2：
我试过的不同时钟是：
CLOCK_MONOTONIC_RAW、CLOCK_PROCESS_CPUTIME_ID 和 CLOCK_REALTIME。他们都提供相同的行为。
此外，我验证了 clock_gettime() 的 return 值以丢弃失败。
看来您是 CPU frequency scaling 的受害者。
CPU频率缩放
您的 CPU 缩放驱动程序根据各种因素调节 CPU 频率，但重要的是根据当前 CPU 负载。 Linux 内核有各种可用的驱动程序，以及不同的缩放调节器。每个驱动程序都可以支持一组特定的缩放调控器，并且根据当前活动的调控器表现不同。
例如，我的笔记本电脑上的默认驱动程序是 intel_pstate，可用的调速器 powersave 和 performance。如果我将驱动程序更改为 acpi-cpufreq，我也会得到 ondemand、userspace 和 conservative。
不同调速器之间的主要区别从它们的名称就可以看出：powersave 调速器会尝试将 CPU 保持在较低的频率以节省电力，而 performance 调速器将尝试将 CPU 保持在高频率以使事情进行得更快。
在某些情况下，performance 调控器只是将 CPU 频率固定为最大可用频率（对我来说，这就是 intel_pstate 驱动程序所发生的情况）。在其他情况下，它只会尝试保持它 "high"，但它仍然会进行调整（对我来说，这就是 acpi-cpufreq 驱动程序所发生的情况）。
在任何情况下，动态 调节 CPU 频率的缩放驱动程序和调速器的组合，将考虑 CPU 负载，以便尽可能即时调整频率。这可能发生在通过系统调用输入内核代码时，或者当内核本身 运行 调度程序重新调度当前 运行ning 进程时的调度滴答上。
发生了什么事？
您很可能拥有动态设置 CPU 频率的缩放驱动程序和调控器的组合。
当你的代码运行s 没有调用usleep()时，CPU负载很重，频率基本稳定。但是，如果您的代码调用 usleep()，CPU 负载会显着降低，并且缩放驱动程序会降低 CPU 频率。当进程在睡眠后被内核唤醒时，频率要低得多，并且缩放驱动程序需要一些时间才能意识到它需要提升。如果您保持定期休眠，驱动程序可能永远没有足够的时间重新调整频率，代码只会 运行 变慢。
这也适用于 printf()，它需要进行 write() 系统调用才能打印文本，并且几乎适用于任何其他系统调用。在用户 space 和内核 space 之间切换会减慢进程，从而使缩放驱动程序降低频率。对于像 clock_gettime() 这样的某些系统调用，这不会发生，它在用户 space 中优化为 运行，并且不需要上下文切换。
这是一个例子，在我的机器上，有一个动态调节器（例如 ondemand）：
您可以清楚地看到 CPU 频率在第一个 运行 期间卡在最大值（ 没有 usleep()），并且然后在第二个运行（和 usleep()）期间上下波动，没有足够的时间稳定下来。事实上，您可以注意到测试 #2 的 avg 时间几乎是测试 #1 的 3 倍。我机器上的 acpi-cpufreq 和调控器 performance 也会发生这种情况。
解决方案
如果您能够设置保持固定 CPU 频率的不同缩放比例 driver/governor 组合，您会发现两个版本的代码在时间上没有差异。
这是另一个例子，在我的机器上，使用静态 CPU 频率（例如，使用 userspace 调速器并手动设置固定速度）：
如您所见，两个测试 运行 几乎同时进行。
如果您无法设置不同的缩放调控器，请尝试更改内核的缩放驱动程序。如果 运行ning Debian 或 Ubuntu，您可能有不同缩放驱动程序的可加载模块。
您可以通过查看当前的内核配置来查看适用于您的内核的可用扩展驱动程序和调控器：
cat /boot/config-$(uname -r) | grep FREQ
例如我可以看到：
...
CONFIG_X86_PCC_CPUFREQ=m
CONFIG_X86_ACPI_CPUFREQ=m
...
其中 m 表示 "available as a module"（可使用 modprobe 加载），y 表示 "built-in"。
然后你可以，例如，尝试做：
# Load acpi-cpufreq since we have CONFIG_X86_ACPI_CPUFREQ=m
sudo modprobe acpi_cpufreq
# Switch driver
echo acpi-cpufreq | sudo tee /sys/devices/system/cpu/cpu*/cpufreq/scaling_driver
# Check available governors for the driver
cat /sys/devices/system/cpu/cpu*/cpufreq/scaling_available_governors
测试代码
这是用于上述 GIF 的基准测试代码：
#define _GNU_SOURCE
#include <unistd.h>
#include <stdio.h>
#include <time.h>
#include <math.h>
#include <sched.h>
#include <sys/types.h>
/**
* Marco Bonelli - 2020-03-02
*
*
* Test the effect of different scaling governors on CPU frequency and
* performance under:
*
* 1) Continuous heavy load.
* 2) Intermittent and short heavy load.
*
* gcc -O3 scaling_governor_test.c -o test
* ./test [N_RUNS] [N_CYCLES_PER_RUN] [TEST2_DELAY_US]
*/
#define DEFAULT_RUNS 1000
#define DEFAULT_CYCLES 1000 * 1000
#define DEFAULT_DELAY 100 * 1000
// Don't optimize this as GCC would basically trash the whole function.
#pragma GCC push_options
#pragma GCC optimize("O0")
void __attribute__ ((noinline)) func(unsigned n) {
double sum = 1.0;
for (unsigned i = 0; i < n; i++)
sum += 0.001;
}
#pragma GCC pop_options
void warmup(unsigned runs, unsigned cycles) {
for (unsigned n = 1; n <= runs; n++)
func(cycles);
}
double bench(unsigned n) {
struct timespec t0, t1;
clock_gettime(CLOCK_PROCESS_CPUTIME_ID, &t0);
func(n);
clock_gettime(CLOCK_PROCESS_CPUTIME_ID, &t1);
return (t1.tv_sec - t0.tv_sec)*1000.0L + (t1.tv_nsec - t0.tv_nsec)/1000.0L/1000.0L;
}
void setup_affinity(void) {
cpu_set_t set;
CPU_ZERO(&set);
CPU_SET(0, &set);
if (geteuid() == 0) {
if (sched_setaffinity(0, sizeof(set), &set) == 0)
puts("Affinity set to CPU #0.");
else
perror("sched_setaffinity");
} else {
puts("Running as normal user, run as root to set CPU affinity.");
}
}
int main(int argc, char **argv) {
unsigned runs, cycles, delay;
double cur, tot1, tot2, min, max, avg;
if (argc < 2 || sscanf(argv[1], "%i", &runs) != 1 || runs < 1)
runs = DEFAULT_RUNS;
if (argc < 3 || sscanf(argv[2], "%i", &cycles) != 1 || cycles < 1)
cycles = DEFAULT_CYCLES;
if (argc < 4 || sscanf(argv[3], "%i", &delay) != 1 || delay < 1)
delay = DEFAULT_DELAY;
setup_affinity();
printf("Benchmarking %u runs of %u cycles each.\n", runs, cycles);
printf("Test #1 will proceed normally.\nTest #2 will usleep(%u) before each run.\n", delay);
fputs("Warming up... ", stdout);
fflush(stdout);
warmup(10, cycles);
puts("done.\n---");
tot1 = 0;
min = INFINITY;
max = -INFINITY;
for (unsigned n = 1; n <= runs; n++) {
cur = bench(cycles);
tot1 += cur;
avg = tot1 / n;
if (cur < min) min = cur;
if (cur > max) max = cur;
printf("\rTest #1: tot %-9.3f avg %-7.3f min %-7.3f max %-7.3f [ms]", tot1, avg, min, max);
fflush(stdout);
}
putchar('\n');
tot2 = 0;
min = INFINITY;
max = -INFINITY;
for (unsigned n = 1; n <= runs; n++) {
usleep(delay);
cur = bench(cycles);
tot2 += cur;
avg = tot2 / n;
if (cur < min) min = cur;
if (cur > max) max = cur;
printf("\rTest #2: tot %-9.3f avg %-7.3f min %-7.3f max %-7.3f [ms]", tot2, avg, min, max);
fflush(stdout);
}
puts("\n---");
if (tot1 < tot2)
printf("Test #2 ran ~%.3fx slower than Test #1.\n", tot2/tot1);
else if (tot1 > tot2)
printf("Test #1 ran ~%.3fx slower than Test #2.\n", tot1/tot2);
else
puts("Reality is a simulation.");
if (avg < 0.5)
puts("Such low average times are not a good indicator. You should re-run the rest with different parameters.");
return 0;
}