【问题标题】:Removing code portions does not match the profiler's data删除代码部分与分析器的数据不匹配
【发布时间】:2014-12-02 20:11:56
【问题描述】:

我正在做一些概念证明并优化示例类型。但是,我遇到了一些我无法完全解释的事情,我希望这里有人可以解决这个问题。

我写了一段很短的sn-p代码:

int main (void)
{
    for (int j = 0; j < 1000; j++)
    {
        a = 1;
        b = 2;
        c = 3;

        for (int i = 0; i < 100000; i++)
        {
            callbackWasterOne();
            callbackWasterTwo();
        }
        printf("Two a: %d, b: %d, c: %d.", a, b, c);
    }
    return 0;
}

void callbackWasterOne(void)
{
    a = b * c;
}
void callbackWasterTwo(void)
{
    b = a * c;
}

它所做的只是调用两个非常基本的函数,它们只是将数字相乘。由于代码相同,我希望分析器 (oprofile) 返回大致相同的数字。

我在每个配置文件中运行此代码 10 次,我得到以下值来表示每个函数花费了多长时间:

  • 主要:平均 = 5.60%,标准差 = 0.10%
  • 回调WasterOne = 43.78%,标准差 = 1.04%
  • 回调WasterTwo = 50.24%,标准差 = 0.98%
  • rest 位于 printf 和 no-vmlinux 等杂项中

callbackWasterOne 和 callbackWasterTwo 的时间差异足够大(至少对我而言),因为它们具有相同的代码,我在代码中切换了它们的顺序并重新运行分析器,现在得到以下结果:

  • 主要:平均 = 5.45%,标准差 = 0.40%
  • 回调WasterOne = 50.69%,标准差 = 0.49%
  • 回调WasterTwo = 43.54%,标准差 = 0.18%
  • rest 位于 printf 和 no-vmlinux 等杂项中

很明显,分析器根据执行顺序对一个比另一个多采样。不好。忽略这一点,我决定看看删除一些代码的效果,我得到了执行时间(平均值):

  • 未删除任何内容:0.5295 秒
  • 从 for 循环中删除了对 callbackWasterOne() 的调用:0.2075 秒
  • 从 for 循环中移除对 callbackWasterTwo() 的调用:0.2042 秒
  • 从 for 循环中删除两个调用:0.1903 秒
  • 删除调用和for循环:0.0025s
  • 删除callbackWasterOne的内容:0.379s
  • 删除callbackWasterTwo的内容:0.378s
  • 删除两者的内容:0.382s

这就是我无法理解的内容:

  • 当我从 for 循环中仅删除一个调用时,执行时间下降了约 60%,这比那个函数 + 主函数所花费的时间还要长!这怎么可能?
  • 与只删除一个调用相比,为什么从循环中删除两个调用的效果如此之小?我无法弄清楚这种非线性。我知道 for 循环很昂贵,但是在那种情况下(如果大部分剩余时间可以归因于执行函数调用的 for 循环),为什么首先删除其中一个调用会导致如此大的改进?

我看了反汇编,两个函数在代码上是一样的。对它们的调用是相同的,删除调用只是删除一个调用行。

其他可能相关的信息

  • 我使用的是 Ubuntu 14.04LTS
  • 代码由 Eclipse 编译,没有优化 (O0)
  • 我通过使用“时间”在终端中运行代码来计时
  • 我使用计数 = 10000 和 10 次重复的 OProfile。

以下是我使用 -O1 优化时的结果:

  • 主要:平均 = 5.89%,标准偏差 = 0.14%
  • callbackWasterOne:avg = 44.28%,stdev = 2.64%
  • callbackWasterTwo:avg = 49.66%,stdev = 2.54%(大于以前)
  • 休息是杂项

去除各种位的结果(平均执行时间):

  • 未删除任何内容:0.522 秒
  • 移除回调WasterOne 调用:0.149 秒(减少 71.47%)
  • 移除回调WasterTwo 调用:0.123%(减少 76.45%)
  • 删除两个调用:0.0365 秒(减少 93.01%)(鉴于上面的配置文件数据,我预计会这样)

所以现在删除一个调用比以前好得多,同时删除两个调用仍然有好处(可能是因为优化器知道循环中没有任何事情发生)。尽管如此,删除一个比我预期的要好得多。

两个函数使用不同变量的结果: 我为 callbackWasterTwo() 定义了另外 3 个变量来使用而不是重复使用相同的变量。现在结果是我所期望的。

  • main: avg = 10.87%, stdev = 0.19%(平均值更大,但可能是因为那些新变量)
  • callbackWasterOne:avg = 46.08%,stdev = 0.53%
  • callbackWasterTwo:avg = 42.82%,stdev = 0.62%
  • 休息是杂项

去除各种位的结果(平均执行时间):

  • 未删除任何内容:0.520 秒
  • 移除回调WasterOne 调用:0.292 秒(减少 43.83%)
  • 移除回调WasterTwo 调用:0.291%(减少 44.07%)
  • 删除两个调用:0.065 秒(减少 87.55%)

所以现在删除两个调用几乎等同于(在 stdev 内)删除一个调用 + 另一个。 由于删除任何一个函数的结果几乎相同(43.83% 对 44.07%),我要冒昧地说,也许分析器数据(46% 对 42%)仍然存在偏差。也许这是它的采样方式(接下来将改变计数器值,看看会发生什么)。

似乎优化的成功与代码重用率密切相关。实现“完全”(你知道我的意思)分析器指出的加速的唯一方法是优化完全独立的代码。无论如何,这一切都很有趣。

不过,我仍在寻找有关-O1 案例减少 70% 的一些解释想法...

我用 10 个函数(每个函数都有不同的公式,但使用了 6 个不同变量的某种组合,一次 3 个,所有乘法):

至少可以说,这些结果令人失望。我知道这些功能是相同的,但是,探查器表明有些需要更长的时间。无论我删除哪一个(“快”或“慢”),结果都是一样的;)所以这让我想知道,有多少人错误地依赖分析器来指示要修复的错误代码区域?如果我在不知不觉中看到了这些结果,有什么可能告诉我去修复 5% 函数而不是 20%(即使它们完全相同)?如果 5% 的问题更容易解决,并且有很大的潜在好处呢?当然,这个分析器可能不是很好,但它很受欢迎!人们使用它!

这是一个屏幕截图。我不想再次输入它:

我的结论:我对 Oprofile 总体上相当失望。我决定通过命令行在同一函数上尝试 callgrind (valgrind),它给了我更合理的结果。事实上,结果非常合理(所有函数都花费了相同的时间执行)。我认为 Callgrind 的样本远远超过 Oprofile 所做的。

Callgrind 仍然不会解释移除一个函数时的改进差异,但至少它给出了正确的基线信息...

【问题讨论】:

  • 顺便说一句,never 没有优化的基准测试。有些人无条件地(并且可以理解地)否决没有优化的基准问题。
  • 我只是想了解会发生什么。如果它被优化了,我就更有可能因为被优化掉而感到困惑。
  • @Mysticial,我添加了使用-O1时的结果。希望这更有用。
  • 1) 我假设 a、b 和 c 是全局的? 2)@Mysticial:当人们认为你应该只分析优化的代码时,我很生气,因为这是一些孩子告诉他们的。关于这个主题还有很多话要说。
  • @Mysticial:就在几天前,我的队友发现/修复了一个缓慢的错误。时间从 144 秒变为 5 秒。他们使用了 VC profiler,加上很多“直觉”。我向他们指出,调试器中的一次暂停会以 97% 的确定性完成,但很难在优化代码上运行调试器。所以它归结为一个人对代码可能存在什么样的速度问题的假设,小问题或大问题。

标签: c++ optimization profiler


【解决方案1】:

啊,我看到你确实看过程序集。这个问题本身确实很有趣,但总的来说,分析未优化的代码是没有意义的,因为即使在 -O1 中也可以轻松减少大量样板。

如果真的只是缺少调用,那么这可以解释时间差异——-O0 堆栈操作代码中有很多样板文件(任何调用者保存的寄存器都必须推入堆栈,并且任何参数同样,然后必须处理任何返回值并且必须进行相反的堆栈操作)这会增加调用函数所需的时间,但不一定完全归因于函数本身 oprofile 因为那代码在实际调用函数之前/之后执行。

我怀疑第二个函数似乎总是花费更少时间的原因是需要完成的堆栈杂耍更少(或没有)——由于前一个函数调用,参数值已经在堆栈上,所以,如您所见,只需执行对函数的调用,无需任何其他额外工作。

【讨论】:

  • 您好,感谢您的回复!我用-O1 重新进行了相同的测量,并用该结果更新了我的原始帖子。其中一些(删除两个通话)现在更有意义,但有些(删除一个通话)甚至更少。 :/ 样板注释有点道理,但是即使堆栈保存/删除归因于 main,执行速度最多不会降低函数本身 + main 占用的量吗?
  • 关于第二个函数花费更少的时间......我认为这是由于缓存或堆栈上的值或类似的东西,但它会与程序集不同,不会不是吗?我认为 O0 代码只会愚蠢地重新保存值。这让我想到我应该尝试为这两个函数设置不同的变量(现在将这样做)。
  • @Mewa:你知道,我同意你的两位 cmets。我不确定为什么时间是这样的。我想也许我的回答可能是错误的:-)
猜你喜欢
  • 1970-01-01
  • 2021-05-06
  • 2018-01-06
  • 2017-02-07
  • 2020-07-29
  • 1970-01-01
  • 1970-01-01
  • 2022-09-23
  • 1970-01-01
相关资源
最近更新 更多