這年頭開發 web 服務很幸福，遇到需要 tune performance 時有很多方便的第三方服務幫你量測，以 Rails 來說可以用的服務像是 NewRelic、Skylight、Scout 等等，很容易幫你調查出是不是有哪些 request 很慢
這些服務好用歸好用，但是大多是 focus 在 ActiveRecord 調用上的調查，沒辦法做到詳細的 code level 瓶頸分析，所以難免還是會遇到需要自己想辦法分析效能瓶頸的情況
初學者找瓶頸方法可能像這樣：
time1 = Time.now# code 1time2 = Time.now# code 2puts time2 - time1
=> execution time of code 1puts Time.now - time2
=> execution time of code 2
簡單粗暴，直接把懷疑很慢的地方的執行時間印出來看就對了，看看哪邊慢。不過一來效率差，二來是如果 code 包含了多個迴圈重複執行某些 code snippets，或者多次調用某些 library，會很難準確評估這些動作總共佔了多少比例的執行時間。
有點經驗的 developer 就會用一些比較進階的 tool 像是 ruby-prof，用法大概像這樣：
require 'ruby-prof'RubyProf.start# ... code to profile ...result = RubyProf.stop# print a flat profile to text
printer = RubyProf::FlatPrinter.new(result)
printer.print(STDOUT)
就可以跑出類似如下的統計結果：
看起來很詳細，但還是不容易理解到底問題發生在哪一段 code。
比如第 8 行，可以明顯發現Hash#initialize_copy 佔了 13.25% 的執行時間，或第 10 行的 String#to_s 佔了 4.02% 的執行時間，但這兩個 method 很可能到處都會用到，到底是哪裡不正常的呼叫這兩個 method 所以花了這麼多時間?
這時候有了火焰圖就一目瞭然了：
有點經驗的人一看就知道，這不就是 call stack 嗎？
圖片下方的藍框 (Statement::Data#set_data) 是程式碼中的某個 method，在其上方有一個Statement::Data#set_data_by_method_name ，代表在 Statement::Data#set_data 這個 method 中會繼續呼叫 Statement::Data#set_data_by_method_name。依此類推繼續呼叫 Fixnum#to..、Fixn.. 並 return 兩層回到 #set_data_by_method_name後，開始呼叫 Hash#deep_merge!，直到最後會抵達最上方藍框標示的 Hash#initialize_copy 。
所以原本在 ruby-prof 看到總執行時間很長的Hash#initialize_copy，原來主要來自於 Statement::Data#set_data 的呼叫！
註1：每個框框佔的橫軸越長代表執行總時間越長。
註2：圖中括號裡的數字代表執行次數 (如下圖，110008次)，把滑鼠移到上面，還可以看到該 method 多次執行加起來的總時間 (21,153 ms)，如下圖：
知道了瓶頸在哪後，去翻翻實作的 code ，大概就知道瓶頸為什麼會發生了。以這個 case 來說，是因為每次 Statement::Data#set_data 執行時，會額外產生不必要的 hash，經過了修正以後，擷取該區域的火焰圖，看起來變成這樣：
Hash#initialize_copy 以及一堆 Hash#deep_merge & Hash#each_pair 從火焰圖上消失了，改三行 code 就把執行時間從 21,153ms 下降到 9,788ms，超爽的啦~
OK，知道火焰圖很好用了，那火焰圖到底要怎麼產生呢？
總共三個步驟：
- 使用 ruby-prof 量測程式碼運作的內容
- 將 1. 的量測結果用 ruby-prof-flamegraph 輸出為 flamegraph 的 raw 檔
- 將 2. 的 flamegraph raw 檔用轉檔 script 轉為 svg 格式的圖檔。此圖檔就是我們要的結果
各步驟說明：
第 1 步
按照 ruby-prof 的說明安裝好 ruby-prof，接著再安裝 ruby-prof-flamegraph。然後用 ruby-prof 量測：
# profile the code
RubyProf.start# ... code to profile ...result = RubyProf.stop
第 2 步
接著把 ruby-prof 量測後的 result 用 ruby-prof-flamegraph 轉成 flamegraph 的 raw 檔
printer = RubyProf::FlameGraphPrinter.new(result)File.open('path/to/output/flame/file.flame', 'w') do |f|
printer.print(f)
end
第 3 步：
上一步產生的 .flame 檔打開來看的話會看不懂，還需要轉成 svg 圖檔。這時候需要用到 performance 界的大神 Brendan D. Gregg 的作品：https://github.com/brendangregg/FlameGraph/blob/master/flamegraph.pl
先把 flamegraph.pl 抓下來，然後執行如下：
./flamegraph.pl your_flame_file.flame > flame.svg接著用瀏覽器或任何可以看 svg 檔的軟體，打開 flame.svg，就可以看到火焰圖了。
—
附帶一提，可以產生火焰圖的 tool 不只一種，大家可以自己玩玩看：
- https://github.com/tmm1/stackprof 搭配 https://github.com/SamSaffron/flamegraph
- https://github.com/MiniProfiler/rack-mini-profiler#flamegraphs
- https://github.com/rbspy/rbspy 可量測執行中的程式， production 環境也可使用
最簡單的方法應該是用第二個 (rack-mini-profiler)，不過缺點是只能用在 rack application，可以分析一般的 Rails request，但以我上面的例子是一個 background job 就不能用。至於第一個就沒有這個限制，API 也很簡單，但是我不太喜歡它的 output 結果，有些時候沒有 ruby-prof-flamegraph 那樣清楚 (其實各有優缺啦…交替著用最好)。
—
References:
- Brendan D. Gregg
http://www.brendangregg.com/index.html - Making sense out of flamegraphs
https://hackernoon.com/making-sense-out-of-flamegraphs-f25e1a0eb760 - Making sense out of flamegraphs
https://hackernoon.com/making-sense-out-of-flamegraphs-f25e1a0eb760 - A New Way to Understand Your Rails App’s Performance
https://www.justinweiss.com/articles/a-new-way-to-understand-your-rails-apps-performance/
喜歡這篇文章的話可以拍拍手讓我知道哦~
按著不放可以快速多拍幾下 :)
