看看如何除錯Ruby的效能問題

Ruby內建的profiler

內建的profiler實現的很簡單，在ruby2.2中只有150行程式碼，大家可以看看它的實現profile.rb 。內建的profiler使用起來非常的方便，只需要加上-rprofile引數即可。例如：

執行：

ruby -rprofile test.rb

輸出結果為：

 %   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格式，兩者的安裝方法如下：

 gem install ruby-prof

ubuntu | sudo apt-get install graphviz
Mac    | brew install graphviz

執行命令很簡單，如下：

 ruby-prof --mode=wall --printer=dot --file=output.dot test.rb 25

此命令的詳細使用方法請參考幫助資訊ruby-prof --help。

上面命令的執行結果會輸出一個graphviz的dot檔案，graphviz提供一個格式轉換命令，可以將此檔案轉換為一個pdf檔案以方便檢視，如下：

 dot -T pdf -o output.pdf output.dot

這樣就可以開啟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 應該很快就能成為很基礎的版本，我們就在這個版本上來做一些測試。

安裝：

 gem install stackprof

這次我們直接在程式碼中使用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命令本身可以解析這個檔案，執行下面的命令：

stackprof tmp/stackprof.dump --text

則會產生下面的結果，結果應該是很清晰的，很明顯在程式碼中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%)     <main>
        75 (100.0%)           0   (0.0%)     block in <main>
        75 (100.0%)           0   (0.0%)     <main>
        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中：

gem 'rack-mini-profiler'

執行：

bundle install

然後重啟你的伺服器，訪問任意的URl，在頁面上的左上角會看到響應時間的毫秒數。如下圖所示：

點選query time(ms)列中的1 sql則可以檢視到執行的sql語句及耗時：

---

本文系OneAPM工程師編譯整理。OneAPM是中國基礎軟體領域的新興領軍企業，能幫助企業使用者和開發者輕鬆實現：緩慢的程式程式碼和SQL語句的實時抓取。想閱讀更多技術文章，請訪問OneAPM官方技術部落格。