性能分析

Profile 模块提供了帮助开发者改进代码性能的工具。当使用时，它会对运行的代码进行测量，并生成输出，帮助你了解在各个代码行上花费了多少时间。最常见的用法是识别“瓶颈”作为优化的目标。

Profile 实施了所谓的“采样”或统计性能分析器。它的工作原理是在执行任何任务期间定期进行回溯。每次回溯都捕获当前正在运行的函数和行号，加上导致此行的所有函数调用的完整链，因此它是当前执行状态的“快照”。

如果你的大部分运行时间都花在了执行特定代码行上，那么这行代码将在所有回溯集中频繁出现。换句话说，给定代码行的“成本”——或者更确切地说，直到并包括这行代码的函数调用序列的成本——与它在所有回溯集中出现的频率成正比。

采样性能分析器不会提供完整的逐行覆盖，因为回溯是以间隔进行的（默认情况下，在 Unix 系统上为 1 毫秒，在 Windows 上为 10 毫秒，尽管实际调度会受到操作系统负载的影响）。此外，正如下面进一步讨论的，由于样本是在所有执行点的一个稀疏子集上收集的，因此采样性能分析器收集的数据会受到统计噪声的影响。

尽管存在这些限制，但采样性能分析器具有相当大的优势

你无需对代码进行任何修改即可进行计时测量。
它可以对 Julia 的核心代码进行性能分析，甚至（可选地）对 C 和 Fortran 库进行性能分析。
由于“不频繁”运行，所以性能开销非常小；在性能分析期间，你的代码可以以接近本机速度运行。

出于这些原因，建议你尝试使用内置的采样性能分析器，然后再考虑任何其他方法。

基本用法

让我们使用一个简单的测试用例

julia> function myfunc()
           A = rand(200, 200, 400)
           maximum(A)
       end

最好先至少运行一次你打算分析的代码（除非你想要分析 Julia 的 JIT 编译器）

julia> myfunc() # run once to force compilation

现在我们准备分析此函数

julia> using Profile

julia> @profile myfunc()

要查看性能分析结果，可以使用几种图形浏览器。一类可视化工具基于 FlameGraphs.jl，每个成员提供不同的用户界面

VS Code 是一个具有内置性能分析可视化支持的完整 IDE
ProfileView.jl 是一个基于 GTK 的独立可视化工具
ProfileVega.jl 使用 VegaLight 并与 Jupyter 笔记本很好地集成
StatProfilerHTML.jl 生成 HTML 并提供一些额外的摘要，并且也与 Jupyter 笔记本很好地集成
ProfileSVG.jl 渲染 SVG
PProf.jl 为检查图形、火焰图等提供本地网站
ProfileCanvas.jl 是一个基于 HTML 画布的性能分析查看器 UI，它由 Julia VS Code 扩展使用，但也可以生成交互式 HTML 文件。

一种完全独立的性能分析可视化方法是 PProf.jl，它使用外部 pprof 工具。

但是，这里我们将使用标准库提供的基于文本的显示

julia> Profile.print()
80 ./event.jl:73; (::Base.REPL.##1#2{Base.REPL.REPLBackend})()
 80 ./REPL.jl:97; macro expansion
  80 ./REPL.jl:66; eval_user_input(::Any, ::Base.REPL.REPLBackend)
   80 ./boot.jl:235; eval(::Module, ::Any)
    80 ./<missing>:?; anonymous
     80 ./profile.jl:23; macro expansion
      52 ./REPL[1]:2; myfunc()
       38 ./random.jl:431; rand!(::MersenneTwister, ::Array{Float64,3}, ::Int64, ::Type{B...
        38 ./dSFMT.jl:84; dsfmt_fill_array_close_open!(::Base.dSFMT.DSFMT_state, ::Ptr{F...
       14 ./random.jl:278; rand
        14 ./random.jl:277; rand
         14 ./random.jl:366; rand
          14 ./random.jl:369; rand
      28 ./REPL[1]:3; myfunc()
       28 ./reduce.jl:270; _mapreduce(::Base.#identity, ::Base.#scalarmax, ::IndexLinear,...
        3  ./reduce.jl:426; mapreduce_impl(::Base.#identity, ::Base.#scalarmax, ::Array{F...
        25 ./reduce.jl:428; mapreduce_impl(::Base.#identity, ::Base.#scalarmax, ::Array{F...

此显示的每一行都代表代码中的一个特定位置（行号）。缩进用于指示嵌套的函数调用序列，缩进越多的行表示调用序列越深。在每一行中，第一个“字段”是在此行或此行执行的任何函数中采取的回溯（样本）数量。第二个字段是文件名和行号，第三个字段是函数名。请注意，由于 Julia 的代码可能会发生变化，因此具体的行号可能会发生变化；如果你想跟踪这些变化，最好自己运行此示例。

在此示例中，我们可以看到调用的是顶层函数，它位于 event.jl 文件中。这是你在启动 Julia 时运行 REPL 的函数。如果你检查 REPL.jl 的第 97 行，你会发现这是调用 eval_user_input() 函数的地方。该函数评估你在 REPL 中输入的内容，并且由于我们正在以交互方式工作，因此当我们输入 @profile myfunc() 时，这些函数被调用。下一行反映了 @profile 宏中采取的操作。

第一行显示在 event.jl 的第 73 行，共采取了 80 次回溯，但这并不意味着这行代码本身“很昂贵”：第三行显示这 80 次回溯实际上是在其对 eval_user_input 的调用中触发的，依此类推。要找出哪些操作实际上占用了时间，我们需要深入调用链。

此输出中的第一行“重要”代码是：

52 ./REPL[1]:2; myfunc()

REPL 指的是我们在 REPL 中定义了 myfunc，而不是将其放入文件中；如果我们使用了文件，那么这里会显示文件名。[1] 表示 myfunc 函数是此 REPL 会话中评估的第一个表达式。myfunc() 的第 2 行包含对 rand 的调用，并且有 52（共 80）次回溯发生在此行。在其下方，你可以看到对 dsfmt_fill_array_close_open! 的调用，它位于 dSFMT.jl 中。

再往下一点，你会看到：

28 ./REPL[1]:3; myfunc()

myfunc 的第 3 行包含对 maximum 的调用，并且在这里采取了 28（共 80）次回溯。在其下方，你可以看到 base/reduce.jl 中执行 maximum 函数对于这种输入数据类型的耗时操作的具体位置。

总的来说，我们可以初步得出结论，生成随机数的成本大约是查找最大元素的两倍。我们可以通过收集更多样本来提高对该结果的信心

julia> @profile (for i = 1:100; myfunc(); end)

julia> Profile.print()
[....]
 3821 ./REPL[1]:2; myfunc()
  3511 ./random.jl:431; rand!(::MersenneTwister, ::Array{Float64,3}, ::Int64, ::Type...
   3511 ./dSFMT.jl:84; dsfmt_fill_array_close_open!(::Base.dSFMT.DSFMT_state, ::Ptr...
  310  ./random.jl:278; rand
   [....]
 2893 ./REPL[1]:3; myfunc()
  2893 ./reduce.jl:270; _mapreduce(::Base.#identity, ::Base.#scalarmax, ::IndexLinea...
   [....]

通常，如果你在某一行收集了 N 个样本，你可以期望误差在 sqrt(N) 数量级（除非有其他噪声来源，比如计算机对其他任务的繁忙程度）。此规则的主要例外是垃圾回收，它很少运行，但往往很昂贵。（由于 Julia 的垃圾回收器是用 C 编写的，因此可以使用下面描述的 C=true 输出模式检测此类事件，或者使用 ProfileView.jl。）

这说明了默认的“树”转储；另一种方法是“平面”转储，它会累积独立于其嵌套关系的计数

julia> Profile.print(format=:flat)
 Count File          Line Function
  6714 ./<missing>     -1 anonymous
  6714 ./REPL.jl       66 eval_user_input(::Any, ::Base.REPL.REPLBackend)
  6714 ./REPL.jl       97 macro expansion
  3821 ./REPL[1]        2 myfunc()
  2893 ./REPL[1]        3 myfunc()
  6714 ./REPL[7]        1 macro expansion
  6714 ./boot.jl      235 eval(::Module, ::Any)
  3511 ./dSFMT.jl      84 dsfmt_fill_array_close_open!(::Base.dSFMT.DSFMT_s...
  6714 ./event.jl      73 (::Base.REPL.##1#2{Base.REPL.REPLBackend})()
  6714 ./profile.jl    23 macro expansion
  3511 ./random.jl    431 rand!(::MersenneTwister, ::Array{Float64,3}, ::In...
   310 ./random.jl    277 rand
   310 ./random.jl    278 rand
   310 ./random.jl    366 rand
   310 ./random.jl    369 rand
  2893 ./reduce.jl    270 _mapreduce(::Base.#identity, ::Base.#scalarmax, :...
     5 ./reduce.jl    420 mapreduce_impl(::Base.#identity, ::Base.#scalarma...
   253 ./reduce.jl    426 mapreduce_impl(::Base.#identity, ::Base.#scalarma...
  2592 ./reduce.jl    428 mapreduce_impl(::Base.#identity, ::Base.#scalarma...
    43 ./reduce.jl    429 mapreduce_impl(::Base.#identity, ::Base.#scalarma...

如果您的代码包含递归，一个潜在的令人困惑的点是“子”函数中的一行代码可能会累积比总回溯次数更多的计数。考虑以下函数定义

dumbsum(n::Integer) = n == 1 ? 1 : 1 + dumbsum(n-1)
dumbsum3() = dumbsum(3)

如果您要分析 dumbsum3，并在执行 dumbsum(1) 时获取回溯，则回溯将如下所示

dumbsum3
    dumbsum(3)
        dumbsum(2)
            dumbsum(1)

因此，这个子函数获得了 3 个计数，即使父函数只获得了 1 个计数。“树”表示法使这更清晰，因此（除其他原因外）可能是查看结果的最有用方法。

累积和清除

来自 @profile 的结果会累积到一个缓冲区中；如果您在 @profile 下运行多段代码，那么 Profile.print() 将显示组合的结果。这可能非常有用，但有时您想重新开始；您可以使用 Profile.clear() 来完成此操作。

控制配置文件结果显示的选项

Profile.print 的选项比我们迄今为止描述的更多。让我们看看完整的声明

function print(io::IO = stdout, data = fetch(); kwargs...)

让我们首先讨论两个位置参数，然后讨论关键字参数

io – 允许您将结果保存到缓冲区，例如文件，但默认情况下是打印到 stdout（控制台）。
data – 包含您要分析的数据；默认情况下，它是从 Profile.fetch() 中获取的，该函数会从预先分配的缓冲区中提取回溯。例如，如果您想分析探查器，您可以说
```
data = copy(Profile.fetch())
Profile.clear()
@profile Profile.print(stdout, data) # Prints the previous results
Profile.print()                      # Prints results from Profile.print()
```

关键字参数可以是以下任何组合

format – 如上所述，决定是否以（默认值，:tree）或不以（:flat）缩进来打印回溯，以指示树结构。
C – 如果为 true，则显示来自 C 和 Fortran 代码的回溯（通常它们会被排除在外）。尝试运行介绍性示例，其中 Profile.print(C = true)。这在决定是 Julia 代码还是 C 代码导致瓶颈时可能非常有用；设置 C = true 还可以提高嵌套的可解释性，但代价是更长的配置文件转储。
combine – 一些代码行包含多个操作；例如，s += A[i] 包含数组引用 (A[i]) 和求和操作。这些对应于生成的机器代码中的不同行，因此在该行上的回溯过程中可能捕获到两个或多个不同的地址。combine = true 将它们合并在一起，这可能是您通常想要的，但是您可以使用 combine = false 为每个唯一的指令指针生成单独的输出。
maxdepth – 在 :tree 格式中限制深度大于 maxdepth 的帧。
sortedby – 控制 :flat 格式中的顺序。:filefuncline（默认值）按源代码行排序，而 :count 按收集样本的数量排序。
noisefloor – 限制样本的启发式噪声门限以下的帧（仅适用于格式 :tree）。建议尝试的值为 2.0（默认值为 0）。此参数隐藏样本，对于这些样本 n <= noisefloor * √N，其中 n 是该行上的样本数量，N 是被调用者的样本数量。
mincount – 限制出现次数少于 mincount 的帧。

文件/函数名称有时会被截断（用 ...），缩进会被截断，开头为 +n，其中 n 是原本应插入的额外空格数（如果有足够的空间）。如果您想要深度嵌套代码的完整概要，通常一个好主意是使用 IOContext 中的宽 displaysize 将其保存到文件

open("/tmp/prof.txt", "w") do s
    Profile.print(IOContext(s, :displaysize => (24, 500)))
end

配置

@profile 只是累积回溯，分析发生在您调用 Profile.print() 时。对于长时间运行的计算，预先分配用于存储回溯的缓冲区很可能被填满。如果发生这种情况，回溯将停止，但您的计算将继续。因此，您可能会错过一些重要的分析数据（发生这种情况时，您将收到警告）。

您可以通过以下方式获取和配置相关参数

Profile.init() # returns the current settings
Profile.init(n = 10^7, delay = 0.01)

n 是您可以存储的指令指针总数，默认值为 10^6。如果您的典型回溯是 20 个指令指针，那么您可以收集 50000 个回溯，这表明统计不确定性小于 1%。这对大多数应用来说可能已经足够了。

因此，您更可能需要修改以秒为单位的 delay，它设置 Julia 在执行请求的计算之间获取快照的时间量。长时间运行的任务可能不需要频繁的回溯。默认设置为 delay = 0.001。当然，您可以减少延迟，也可以增加延迟；但是，探查的开销会随着延迟变得与获取回溯所需的时间（在作者的笔记本电脑上约为 30 微秒）相似而增加。

内存分配分析

提高性能最常用的技术之一是减少内存分配。Julia 提供了几个工具来衡量这一点

`@time`

可以使用 @time、@allocated 和 @allocations 来衡量总分配量，并且通常可以通过分析这些行造成的垃圾回收成本，从分析中推断出触发分配的特定行。但是，有时直接测量每行代码分配的内存量更有效。

GC 日志记录

虽然 @time 会记录有关在评估表达式过程中内存使用情况和垃圾回收的高级统计信息，但记录每个垃圾回收事件可能很有用，从而直观地了解垃圾回收器运行的频率、每次运行的时间以及每次收集的垃圾量。可以使用 GC.enable_logging(true) 来启用此功能，这会导致 Julia 在每次发生垃圾回收时将日志记录到 stderr。

分配探查器

Julia 1.8

此功能需要至少 Julia 1.8。

分配探查器记录每个分配的堆栈跟踪、类型和大小，同时它正在运行。可以使用 Profile.Allocs.@profile 来调用它。

有关分配的信息作为 Alloc 对象数组返回，包装在 AllocResults 对象中。目前，可视化这些信息的最佳方式是使用 PProf.jl 和 ProfileCanvas.jl 包，它们可以可视化导致分配最多的调用堆栈。

分配探查器确实具有相当大的开销，因此可以传递 sample_rate 参数，通过使其跳过一些分配来加快速度。传递 sample_rate=1.0 将使其记录所有内容（速度很慢）；sample_rate=0.1 将只记录 10% 的分配（速度更快）等等。

注意

分配探查器的当前实现不会捕获所有分配的类型。探查器无法捕获类型的分配将表示为具有类型 Profile.Allocs.UnknownType。

您可以在此处阅读有关丢失类型和改进此问题的计划的更多信息：问题 #43688。

逐行分配跟踪

衡量分配的另一种方法是使用 --track-allocation=<setting> 命令行选项启动 Julia，对于该选项，您可以选择 none（默认值，不测量分配）、user（测量除 Julia 核心代码之外的所有地方的内存分配）或 all（测量 Julia 代码的每行代码的内存分配）。将为每行编译代码测量分配。退出 Julia 时，累积结果将写入具有 .mem 后缀的文件，该文件位于与源文件相同的目录中。每行都列出了分配的总字节数。 Coverage 包包含一些基本的分析工具，例如按分配的字节数对行进行排序。

在解释结果时，有一些重要的细节。在 user 设置下，从 REPL 直接调用的任何函数的第一行将表现出分配，这是由于在 REPL 代码本身中发生的事件造成的。更重要的是，JIT 编译也会增加分配计数，因为 Julia 的大部分编译器都是用 Julia 编写的（编译通常需要内存分配）。推荐的程序是通过执行您要分析的所有命令来强制编译，然后调用 Profile.clear_malloc_data() 来重置所有分配计数器。最后，执行所需的命令并退出 Julia 以触发 .mem 文件的生成。

注意

--track-allocation 会更改代码生成以记录分配，因此分配可能与没有该选项时的情况不同。我们建议改为使用分配探查器。

外部分析

目前 Julia 支持 Intel VTune、OProfile 和 perf 作为外部分析工具。

根据您选择的工具，使用 USE_INTEL_JITEVENTS、USE_OPROFILE_JITEVENTS 和 USE_PERF_JITEVENTS 在 Make.user 中设置为 1 进行编译。支持多个标志。

在运行 Julia 之前，将环境变量 ENABLE_JITPROFILING 设置为 1。

现在您有很多方法可以使用这些工具！例如，对于 OProfile，您可以尝试简单的记录

>ENABLE_JITPROFILING=1 sudo operf -Vdebug ./julia test/fastmath.jl
>opreport -l `which ./julia`

或者类似地，对于 perf

$ ENABLE_JITPROFILING=1 perf record -o /tmp/perf.data --call-graph dwarf -k 1 ./julia /test/fastmath.jl
$ perf inject --jit --input /tmp/perf.data --output /tmp/perf-jit.data
$ perf report --call-graph -G -i /tmp/perf-jit.data

您还可以测量程序的许多其他有趣内容，要获得完整的列表，请阅读 Linux perf 示例页面。

请记住，perf 会为每次执行保存一个 perf.data 文件，即使对于小型程序，该文件也会变得相当大。此外，perf LLVM 模块会在 ~/.debug/jit 中临时保存调试对象，请记住经常清理该文件夹。