性能分析工具的利与弊

2019 年 9 月 16 日 | Jameson Nash

性能分析工具很棒。它们让我们能够了解实际影响程序性能的因素。性能分析工具也很糟糕。它们会欺骗我们并提供令人困惑的信息。它们还有一些令人惊讶的新发展:brendangregg 经常克隆的火焰图工具 是在 2011 年创建的!因此,我将在这里研究一些改进性能分析报告的方法;并研究它们通常出现故障的方式,以提高对报告中这些伪影的认识。

了解更多!

如果您想了解它们的预期工作方式,我建议您首先查看其他资源,例如

然后回到这里深入探讨!

深入探讨更深的堆栈

我想研究几个性能分析器,看看它们如何处理递归。这是一个棘手的领域,既要让编译器输出有用的基准,又要让性能分析工具总结对它的解释。由于我在 Julia 上工作,我可以尝试修复我发现的问题,让世界变得更美好!对于我测试的其他工具,我希望这些观察结果可以帮助这些项目从其他项目中学习改进方法。因此,如果看起来我只是喜欢发现问题,那是真的,但我也正在通过这项工作积极地进行修复和改进。

测试单元

我们将使用递归斐波那契作为我们的测试函数,因为它在大多数语言中都很容易编写,但我们没有看到编译器变得“过于聪明”并消除递归。这是我们将使用的基本公式

fib(n) :
    n > 1 => fib(n - 1) + fib(n - 2)
    else  => 1

此外,我们还将尝试使每个递归调用实际上通过另一个函数间接进行,以提供稍微更复杂的回溯

fib_r(n) : fib(n)

性能分析 C 代码

首先,让我们看看一个 C 程序示例

int fib(int n);
int fib_r(int n) {
    return fib(n);
}
int fib(int n) {
    return n > 1 ? fib_r(n - 1) + fib_r(n - 2) : 1;
}
int main(void) {
    return fib(40);
}

在我的 macOS 机器上,这大约需要一秒钟,所以通常这是一个很好的样本数量。我将使用一些选项来防止某些堆栈优化,并在其他情况下让编译器尽其所能。-fno-optimize-sibling-calls 选项禁止编译器使用尾调用,这确保 fib_r 保留在堆栈跟踪记录中,并且 fib 不能被部分优化为循环。-fno-inline 用于帮助保持记录的可预测性。

$ clang -Wall -Werror -pedantic -std=c11 -fno-optimize-sibling-calls -fno-inline -O3 -g fib.c -o fib
$ time ./fib
real    0m0.723s
user    0m0.717s
sys     0m0.003s
$ instruments -t "Time Profiler" ./fib
Instruments Trace Complete: instrumentscli0.trace
$ open instrumentscli0.trace

Instruments.app 中,这做得很好,除了一个奇怪的选项组合。

Instruments.app bad result

我不知道它是如何计算这些数字的,但请注意总运行时间为 738 毫秒,因此所有这些数字都是该数字的倍数(1.47 秒、1.15 秒、230 毫秒)都是错误的。

但在任何其他模式下,我们都可以看到它走在了正确的轨道上

Instruments.app good result

我在这里唯一能确定的问题是,在此视图中所有自权重均为零。在源代码视图中,这些行用计数正确地进行了注释。

在 Linux 上,使用 perf 工具,这与使用类似

$ gcc -Wall -Werror -pedantic -std=c11 -fno-optimize-sibling-calls -fno-inline -O3 -g fib.c
$ perf record --call-graph dwarf ./a.out
[ perf record: Woken up 153 times to write data ]
[ perf record: Captured and wrote 38.221 MB perf.data (4748 samples) ]

但我无法生成令人满意的报告。我认为错误在于 dwarf 的实现,因此在使用它做出决策时应谨慎。

$ perf report --stdio --call-graph=none
# Total Lost Samples: 0
#
# Samples: 4K of event 'cycles:uppp'
# Event count (approx.): 3344003009
#
# Children      Self  Command  Shared Object     Symbol
# ........  ........  .......  ................  ..................................
#
    64.22%    64.22%  a.out    a.out             [.] fib
    43.30%    35.77%  a.out    a.out             [.] fib_r
     8.75%     0.00%  a.out    [unknown]         [.] 0x00007ffc2454634f
     7.52%     0.00%  a.out    a.out             [.] _start
     7.52%     0.00%  a.out    a.out             [.] main

我尝试了各种选项,包括 -gdwarf-2-gdwarf-4-fno-omit-frame-pointer[1],以及切换到 clang。这些都没有多大帮助。在禁用 FPO 的情况下,clang 的结果比 gcc 好得多(两者都有所改进),但 clang 的输出运行速度也稍慢,因此这可能是导致因素(开销更大)。

但是将编译器选项 -fno-omit-frame-pointer 与 perf 选项 --call-graph fp 结合使用有效。

$ perf report --stdio --call-graph=none
# Total Lost Samples: 0
#
# Samples: 4K of event 'cycles:uppp'
# Event count (approx.): 2752040208
#
# Children      Self  Command  Shared Object     Symbol
# ........  ........  .......  ................  ..........................
#
    99.99%    65.02%  a.out    a.out             [.] fib
    99.99%    34.97%  a.out    a.out             [.] fib_r
    99.99%     0.00%  a.out    a.out             [.] main
    99.99%     0.00%  a.out    libc-2.27.so      [.] __libc_start_main
    99.99%     0.00%  a.out    [unknown]         [.] 0x077e258d4c544155

在这里,我们看到它具有正确的子项(总计)和自权重!

--call-graph 还有很多其他选项,但所有这些选项都产生了大量(错误的)信息,因此我选择不在这里尝试拟合。

性能分析 JuliaLang 代码

现在让我们看看 JuliaLang (v1.3) 的表现如何

julia> @noinline function fib(n)
         return n > 1 ? fib_r(n - 1) + fib_r(n - 2) : 1
       end

julia> @noinline fib_r(n) = fib(n)

julia> @time fib(40)
  0.738735 seconds (3.16 k allocations: 176.626 KiB)
165580141

julia> using Profile

julia> @profile fib(40)
165580141

julia> Profile.print(format=:flat, sortedby=:count)
 Count File      Line Function
    12 int.jl      52 -
    14 int.jl      53 +
   212 boot.jl    330 eval
  5717 REPL[2]      1 fib_r
  6028 REPL[1]      2 fib

julia> count(==(0), Profile.fetch())
585

这很糟糕——根据堆栈顶部 eval 函数上的计数,我们似乎大约有 212 个样本。并且我们被告知大约 2000% 的时间在 fib 中。显然不正确。这里发生了什么?我们计算出 fib(和 fib_r)在每个回溯中平均出现 10-20 次,因此我们在我们的扁平格式输出中过度表示了它们。好的,所以首先要解决这个问题:每个帧在每个输出行中只应计算一次。

但是还有递归选项,它没有受到此特定问题的影响。那么它的表现如何呢

julia> Profile.print(format=:tree)
260 REPL[1]:2; fib(::Int64)
112 REPL[1]:1; fib_r(::Int64)
212 task.jl:333; REPL.var"##26#27"
 212 REPL.jl:118; macro expansion
  212 REPL.jl:86; eval_user_input
   212 boot.jl:330; eval
  ╎ 210 REPL[1]:2; fib
  ╎  210 REPL[1]:1; fib_r
  ╎   210 REPL[1]:2; fib
  ╎    210 REPL[1]:1; fib_r
  ╎     210 REPL[1]:2; fib
  ╎    ╎ 210 REPL[1]:1; fib_r
  ╎    ╎  210 REPL[1]:2; fib
  ╎    ╎   210 REPL[1]:1; fib_r
  ╎    ╎    210 REPL[1]:2; fib
  ╎    ╎     210 REPL[1]:1; fib_r
  ╎    ╎    ╎ 210 REPL[1]:2; fib
  ╎    ╎    ╎  210 REPL[1]:1; fib_r
  ╎    ╎    ╎   210 REPL[1]:2; fib
  ╎    ╎    ╎    210 REPL[1]:1; fib_r
  ╎    ╎    ╎     210 REPL[1]:2; fib
  ╎    ╎    ╎    ╎ 210 REPL[1]:1; fib_r
  ╎    ╎    ╎    ╎  210 REPL[1]:2; fib
  ╎    ╎    ╎    ╎   210 REPL[1]:1; fib_r
  ╎    ╎    ╎    ╎    210 REPL[1]:2; fib
  ╎    ╎    ╎    ╎     210 REPL[1]:1; fib_r
  ╎    ╎    ╎    ╎    ╎ 210 REPL[1]:2; fib
  ╎    ╎    ╎    ╎    ╎  210 REPL[1]:1; fib_r
  ╎    ╎    ╎    ╎    ╎   210 REPL[1]:2; fib
  ╎    ╎    ╎    ╎    ╎    210 REPL[1]:1; fib_r
  ╎    ╎    ╎    ╎    ╎     210 REPL[1]:2; fib
  ╎    ╎    ╎    ╎    ╎    ╎ 210 REPL[1]:1; fib_r
  ╎    ╎    ╎    ╎    ╎    ╎  210 REPL[1]:2; fib
  ╎    ╎    ╎    ╎    ╎    ╎   210 REPL[1]:1; fib_r
  ╎    ╎    ╎    ╎    ╎    ╎    210 REPL[1]:2; fib
  ╎    ╎    ╎    ╎    ╎    ╎     210 REPL[1]:1; fib_r
  ╎    ╎    ╎    ╎    ╎    ╎    ╎ 210 REPL[1]:2; fib
  ╎    ╎    ╎    ╎    ╎    ╎    ╎  210 REPL[1]:1; fib_r
  ╎    ╎    ╎    ╎    ╎    ╎    ╎   209 REPL[1]:2; fib
  ╎    ╎    ╎    ╎    ╎    ╎    ╎    208 REPL[1]:1; fib_r
  ╎    ╎    ╎    ╎    ╎    ╎    ╎     208 REPL[1]:2; fib
  ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎ 208 REPL[1]:1; fib_r
  ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎  208 REPL[1]:2; fib
  ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎   208 REPL[1]:1; fib_r
  ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    208 REPL[1]:2; fib
  ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎     206 REPL[1]:1; fib_r
  ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎ 205 REPL[1]:2; fib
  ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎  203 REPL[1]:1; fib_r
  ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎   201 REPL[1]:2; fib
  ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    199 REPL[1]:1; fib_r
  ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎     199 REPL[1]:2; fib
  ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎ 196 REPL[1]:1; fib_r
  ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎  194 REPL[1]:2; fib
  ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎   190 REPL[1]:1; fib_r
  ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    187 REPL[1]:2; fib
  ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎     1   REPL[1]:2; fib
  ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎     175 REPL[1]:1; fib_r
  ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎ 170 REPL[1]:2; fib
  ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎  4   REPL[1]:2; fib
  ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎  151 REPL[1]:1; fib_r
  ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎   143 REPL[1]:2; fib
  ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    2   REPL[1]:2; fib
  ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    120 REPL[1]:1; fib_r
  ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎     109 REPL[1]:2; fib
  ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎ 85 REPL[1]:1; fib_r
  ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎  76 REPL[1]:2; fib
  ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎   56 REPL[1]:1; fib_r
  ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    48 REPL[1]:2; fib
  ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎     3  REPL[1]:2; fib
  ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎     28 REPL[1]:1; fib_r
  ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎ 26 REPL[1]:2; fib
  ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎  10 REPL[1]:1; fib_r
  ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎   7 REPL[1]:2; fib
  ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    2 REPL[1]:1; fib_r
  ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    1 int.jl:52; -
  ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎  1  int.jl:53; +
  ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎  1  int.jl:52; -
  ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎   1  int.jl:52; -
  ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎ 1  int.jl:53; +
  ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎ 4  int.jl:52; -
  ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    5   int.jl:53; +
  ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    2   int.jl:52; -
  ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎  2   int.jl:53; +
  ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎  2   int.jl:52; -
  ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎     1   int.jl:53; +
  ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎   1   int.jl:52; -
  ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎ 1   int.jl:53; +
  ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    1   int.jl:53; +
  ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎    ╎  2   int.jl:53; +

我们还看到它在许多情况下(几乎 40% 失败!)在识别堆栈方面存在问题,类似于 perf。改进这一点的一种方法(将失败率降低到约 10%)是禁用省略帧指针选项,就像我们之前做的那样。目前这需要此源代码更改

diff --git a/src/jitlayers.cpp b/src/jitlayers.cpp
index cf339d8a4b..f6e9c08e2c 100644
--- a/src/jitlayers.cpp
+++ b/src/jitlayers.cpp
@@ -3,9 +3,7 @@
 #include "llvm-version.h"
 #include "platform.h"
 #include "options.h"
-#if defined(_OS_WINDOWS_) || defined(_OS_FREEBSD_)
 #  define JL_DISABLE_FPO
-#endif

 #include <iostream>
 #include <sstream>

但除此之外,这看起来相当准确,但是哇,多么可怕的箭头!我需要以这种方式超过 40 个帧,这使得它很难解释。像这样的尖峰帧图在查看时可能会产生误导,因为重要的是宽度的总和,但视觉上最引人注目的区域(尖峰)是正交轴。因此,这种布局可能使人们很难看到总共花费了多少时间,尤其是在递归导致重要宽度的高度垂直移动的情况下。

Julia 实现了一些选项,包括 noisefloormincountmaxdepth,以帮助解决许多情况,但它们对本例无效。mincount 选项(在 Instruments.app 中也存在用于最小和最大样本数;在 perf 中作为最小百分比阈值)会删除任何未达到该阈值的行。maxdepth 选项(在 perf 中也称为 print_limit)在某个递归限制后截断树。noisefloor 选项类似于 mincount,但作为父帧中噪声估计的相对分数运行,而不是常量阈值(我不知道其他工具中是否有类似的选项)。这可以帮助隐藏对即时性能贡献不大的树中的帧。这是基于价值工程的原则,即首先关注最大的贡献者和给定为 child < noisefloor*sqrt(parent) 的采样噪声的统计测量。对于许多问题,这些选项可以极大地帮助快速隔离最大的贡献者。

但是,以上述树状图为例,这些选项均无助于解决问题。我们需要在工具箱中添加更多工具!

现在让我们检查一下如何尝试以某种方式合并递归帧。一个选项是我们之前看到的扁平报告。

这是上面相同的扁平报告,其中计数已更正(在 Julia v1.4-dev 中),并且还为此编译了一些额外信息

julia> Profile.print(format=:flat, sortedby=:counts)
 Count  Overhead File      Line Function
   228         2 ./boot.jl  330 eval
     2         2 ./int.jl    52 -
    25        25 ./int.jl    53 +
   321       155 ./REPL[2]    1 fib_r
   514       426 ./REPL[1]    2 fib
Total snapshots: 610

这更好,现在信息与树匹配!但与树视图不同,此扁平视图不显示上下文。其中一些函数非常常见,例如 +,并且可能不足以像这样聚合地查看它们。我们可以以某种方式结合这两种视图的优点吗?

更好的递归处理

现在让我们看看一些工具采用的一些不同的方法来展平这种递归,以便更容易找到见解。

首先,我们上面看到的 Instruments.app 工具有一个折叠递归调用的选项,它将采用一个具有一个重复条目的调用栈,并用一个条目替换它,该条目采用该递归的总和。这对我们的示例代码没有影响,因为有两个条目正在重复。虽然此模式可以简化堆栈视图并使其更易于浏览,但它没有为我们提供对代码的额外见解。

还有一个名为 Speedscope 的仅可视化工具,它有一个执行此操作的选项。它导入由许多其他工具和语言创建的配置文件,因此我们将导入早期的 perf 文件,看看它在我们阵容中的表现如何

Speedscope bad result

看起来差不多!只有一个愚蠢的小问题:它声称所有与突出显示的帧相同的帧(仅自身)的总和为 367.38 毫秒(良好),但突出显示的帧本身为 1.05 秒(糟糕,该工具必须计算错误的摘要信息的计数)。但除此之外,这似乎显示了我们期望的大致正确信息。

让我们更仔细地看看它使用其堆栈折叠递归示例执行的操作,其中左侧视图和“r”递归扁平化视图显示了一个解决方案。在这里,我们看到它在检查调用树时只是删除任何重复的帧。这对于我们简单的 fib 示例来说效果很好,但当我们查看其样本数据时会显示一些伪影。注意蓝色帧 (c) 如何始终被计入绿色帧 (b),即使一半的调用实际上来自红色帧 (a)?

当我向我的朋友展示这篇文章时,他建议我也包含他的PProf.jl 包在这里(一个用于pprof 可视化工具的 JuliaLang 前端)。这是一个很好的建议,因为它提供了几个替代图形表示。首先,它可以生成 callgrind 格式的图形

PProf

这很好!我们可以同时可视化静态函数的调用树以及每个函数对时间做出的贡献权重。但是,此格式在可以容纳的信息总量方面可能有点受限,因此它可能并不总是有效。pprof 工具会自动过滤掉较小的帧以帮助用户查看重要的帧,并提供一些用于添加和删除视图中函数的选项。

此外,pprof 工具还有一个三明治文本报告,总结了每个配置文件样本周围的调用方和被调用方列表

Type: events
Showing nodes accounting for 632, 100% of 632 total
----------------------------------------------------------+-------------
      flat  flat%   sum%        cum   cum%   calls calls% + context
----------------------------------------------------------+-------------
                                               273 52.20% |   fib REPL:-1
                                               273 52.20% |   fib_r REPL:1
       417 65.98% 65.98%        523 82.75%                | fib REPL:2
                                               273 52.20% |   fib_r REPL:1
----------------------------------------------------------+-------------
                                               273 72.03% |   fib REPL:2
       178 28.16% 94.15%        379 59.97%                | fib_r REPL:1
                                               273 72.03% |   fib REPL:2
                                                33  8.71% |   + ./int.jl:2
                                                 1  0.26% |   - ./int.jl:2
----------------------------------------------------------+-------------
                                                33   100% |   + ./int.jl:2 (inline)
        33  5.22% 99.37%         33  5.22%                | + ./int.jl:53
----------------------------------------------------------+-------------
                                                 1   100% |   - ./int.jl:2 (inline)
         1  0.16% 99.53%          1  0.16%                | - ./int.jl:52
----------------------------------------------------------+-------------

让我们结合所有这些想法,为我们的 Julia 纯文本树视图创建一个新选项:扁平化递归。这是 Profile.print 的新参数的文档字符串

因此,这将不再是对堆栈的逐字解释,而是显示一个特定的线性化,其中每个递归调用都被重写为循环。这有一些次要的影响。这意味着我们现在可能会看到总和大于其父级的计数。例如,在父级fib内部的 100%(236/236)的时间都花费在子级fib_r内部,此外,还有 4%(9/236)被记录为是fibfib直接调用的一部分(由不可靠的堆栈记录导致的人为因素)。此外,如果您还记得上面fib的定义,fib有两个不同的对fib_r的调用。由于目标是重新排列递归调用,而不是递归行,因此我们也期望在配置文件形状中精确地看到这两个调用。但是,没有区分每个调用来自哪个调用(除非您还传递了collapse=false[2])。

julia> Profile.print(format=:tree, recur=:flat)
94  ./REPL[1]:1; fib_r(::Int64)
260 ./REPL[2]:2; fib(::Int64)
275 ./task.jl:333; (::REPL.var"##26#27"{REPL.REPLBackend})()
 275 ./REPL.jl:118; macro expansion
  275 ./REPL.jl:86; eval_user_input(::Any, ::REPL.REPLBackend)
   275 ./boot.jl:330; eval(::Module, ::Any)
  ╎ 273 ./REPL[2]:2; fib(::Int64)
  ╎  273 ./REPL[1]:1; fib_r(::Int64)
  ╎   273 ./REPL[2]:2; fib(::Int64)
  ╎    49 ./REPL[1]:1; fib_r(::Int64)
  ╎    1  ./REPL[2]:2; fib(::Int64)
  ╎    39 ./int.jl:53; +
  ╎    3  ./int.jl:52; -
  ╎  1   ./REPL[2]:2; fib(::Int64)
Total snapshots: 629

我认为这看起来很酷,甚至模糊地展示了我在脑海中如何概念化这些函数。这目前仅在我的jn/profile-recurflat分支上可用,但很快就会成为一个 PR,并在 JuliaLang v1.4 版本中出现。

最终想法

还有许多其他用于检查配置文件探索工具的工具我还没有提到,包括久负盛名的ProfileView.jlJuno.jl。还有其他工具可用于处理性能问题,例如简单的@time 和功能齐全的BenchmarkTools.jl。这些通常会导致需要对代码进行更深入的探索。对于下一步,请考虑使用Cthulhu.jl学习更多关于其他类型的调试

最后,我们正在为 JuliaLang 开发一个内存分析器,让您探索内存消耗问题,类似于上面探讨的时间持续时间消耗问题。因此,请关注更多更新!


[1] 在编写本文时,我忘记了测试--fasynchronous-unwind-tables 标志到gcc,它应该准确无误。但是,它似乎对perf没有影响。我的理解是,此标志在 x86-64 上已经是默认设置。为了确认这一点,我测试了反向标志(-fno-asynchronous-unwind-tables)并注意到这确实使结果变得更糟。
[2] collapse=false 选项控制是按行号合并概要文件还是按指令指针保持它们的不同。一个有用的代码维护技巧是尝试确保每一行都做相对较少的事情,以便行号成为信息的确切来源。这不需要达到极致,就像我下面作为示例所做的那样(几乎手动编写3AC),因为其中许多语句可能会被优化并移动。但有时能够查看我们示例中一个fib_r调用是否比另一个更昂贵,或者仅仅从堆栈跟踪中知道正在索引哪个数组等,这可能非常有价值。

@noinline function fib(n)
    if n > 1
        n -= 1
        x1 = fib_r(n)
        n -= 1
        x2 = fib_r(n)
        y = x1 + x2
    else
        y = 1
    end
    return y
end

后记:Profile.jl 中也存在一个越界查找错误,很快就会解决。这几乎从来都不是问题,但我们有时会注意到它作为虚假信息显示了一些永远不应该到达的帧。例如,我们可以分析对昂贵的cpuid指令的调用,并看到有一个虚假的帧,使其看起来我们使用了某些恰好位于目标函数外部的代码,不知何故正在被使用。

julia> testf() = for i = 1:10^7; ccall(:jl_cpuid, Cvoid, (Ref{NTuple{4,Int32}}, Int32), (0,0,0,0), 0); end
julia> @profile testf()
julia> Profile.print(C=true)
201 ./REPL[2]:1; testf()
 199 ./REPL[1]:1; cpuid
  3   ./processor_x86.cpp:8; jl_cpuid
  192 ./processor_x86.cpp:12; jl_cpuid
  1   ./libjulia.1.4.dylib:?; _GLOBAL__sub_I_runtime_ccall.cpp