看看如何調試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官方技術博客。