看看如何调试Ruby的性能问题
李哲 — APRIL 08, 2015
Ruby内置的profiler
内置的profiler实现的很简单，在ruby2.2中只有150行代码，大家可以看看它的实现profile.rb 。内置的profiler使用起来非常的方便，只需要加上-rprofile参数即可。例如：
执行：
- % cumulative self self total
- time seconds seconds calls ms/call ms/call name
- 24.24 0.16 0.16 10001 0.02 0.06 Object#m2
- 18.18 0.28 0.12 2 60.00 330.00 Integer#times
- 18.18 0.40 0.12 10001 0.01 0.06 Object#m1
- 15.15 0.50 0.10 10001 0.01 0.01 Class#new
- 10.61 0.57 0.07 10000 0.01 0.01 P1.new
- 6.06 0.61 0.04 20000 0.00 0.00 Fixnum#to_s
- 4.55 0.64 0.03 10000 0.00 0.00 Struct#initialize
- 3.03 0.66 0.02 10000 0.00 0.00 P2#initialize
- 0.00 0.66 0.00 1 0.00 0.00 TracePoint#enable
- 0.00 0.66 0.00 1 0.00 0.00 Class#initialize
- 0.00 0.66 0.00 1 0.00 0.00 nil#
- 0.00 0.66 0.00 1 0.00 0.00 Struct.new
- 0.00 0.66 0.00 7 0.00 0.00 Module#method_added
- 0.00 0.66 0.00 3 0.00 0.00 BasicObject#singleton_method_added
- 0.00 0.66 0.00 2 0.00 0.00 Class#inherited
- 0.00 0.66 0.00 2 0.00 0.00 IO#set_encoding
- 0.00 0.66 0.00 1 0.00 0.00 TracePoint#disable
- 0.00 0.66 0.00 1 0.00 660.00 #toplevel
通过打印出的结果能够很明显的看出耗时的方法。内置的profiler很简单，只能打印出这样的结果，没有 其他输出格式的选项，下面介绍的其他几种都有丰富的格式输出。
ruby-prof
repo: https://github.com/ruby-prof/ruby-prof
ruby-prof 具有C扩展，所以它能运行的更快，同时它支持丰富的输出格式，方便我们去查找性能瓶颈。 ruby-prof支持输出GraphViz 支持的dot格式，两者的安装方法如下：
执行命令很简单，如下：
上面命令的执行结果会输出一个graphviz的dot文件，graphviz提供一个格式转换命令，可以将此文件转换为一个pdf文件以方便查看，如下：
这样就可以打开output.pdf查看程序内的方法调用占比了。
perftools.rb
repo: https://github.com/tmm1/perftools.rb
perftools.rb是google-perftools的ruby版本，不过它只支持ruby2.1以下版本，2.1及以上 版本就需要用到下面的stackprof了，这两个工具都是一个人写的。鉴于此，我们略过perftools.rb， 作者实现stackprof，就是为了替代perftools.rb。如果有需求的话，就请参考其github主页。
stackprof
repo: https://github.com/tmm1/stackprof
stackprof只支持Ruby2.1+，不过现在ruby的版本发布很快，每一个版本都能带来一些新东西，2.1 应该很快就能成为很基础的版本，我们就在这个版本上来做一些测试。
安装：
这次我们直接在代码中使用stackprof的方法：
- require 'stackprof'
- def m1
- 5_000_000.times{ 1+2+3+4+5 }
- end
- def m2
- 1_000_000.times{ 1+2+3+4+5 }
- end
- StackProf.run(mode: :cpu, out: 'tmp/stackprof.dump') do
- m1
- m2
- end
我们执行这个ruby程序，ruby test.rb，会在当前目录的tmp目录中产生一个文件stackprof.dump, 然后来分析以下这个文件，stackprof命令本身可以解析这个文件，执行下面的命令：
则会产生下面的结果，结果应该是很清晰的，很明显在代码中m1方法要占有绝大部分的运行时间。
- Mode: cpu(1000)
- Samples: 75 (0.00% miss rate)
- GC: 0 (0.00%)
- =====================================================================
- TOTAL (pct) SAMPLES (pct) FRAME
- 62 (82.7%) 62 (82.7%) block in Object#m1
- 13 (17.3%) 13 (17.3%) block in Object#m2
- 75 (100.0%) 0 (0.0%)
- 75 (100.0%) 0 (0.0%) block in
- 75 (100.0%) 0 (0.0%)
- 62 (82.7%) 0 (0.0%) Object#m1
- 13 (17.3%) 0 (0.0%) Object#m2
其他更加丰富的输出方式和分析方式，就请参考stackprof的github主页，讲解的很全面。
如果你希望在web前端中展示相关信息，就请看看stackprof-webnav这个gem，它提供了比较全面的 展示，操作等等，适合在一些web应用中使用，github地址：stackprof-webnav
rack-mini-profiler
repo: https://github.com/MiniProfiler/rack-mini-profiler
rack-mini-profiler专门应用于基于rack的web应用的性能调优，在rails中的使用方法如下：
首先将gem添加到gemfile中：
执行：
然后重启你的服务器，访问任意的URl，在页面上的左上角会看到响应时间的毫秒数。如下图所示：
点击query time(ms)列中的1 sql则可以查看到执行的sql语句及耗时：