この記事はアピリッツの技術ブログ「DoRuby」から移行した記事です。情報が古い可能性がありますのでご注意ください。
https://github.com/kainosnoema/rack-lineprof
rack-lineprofって?
1行毎の負荷の重みをログ出力してくれるとても便利なgemです。
NewRelicではカスタムしないと出してくれないロジック部分の負荷も詳細に分かるようになります。
どうやって使うの?
githubのREADMEにも書かれていますが、gemをinstallした後に
config.ruに
config.middleware.useラック:: Lineprof
を追記して(このままだと本番環境でも動いちゃうのでそこ辺りは気を付けて)、
curl'http:// localhost:3000 / slow-page?lineprof = active_support / core_ext / string '
というように、lineprof=”負荷を調査したいファイル”というパラメータを追加してAPIを投げるだけです。
使いづらい点
ゲームサーバーに限らず、認証情報などをリクエストヘッダに加えて安全性を高めているAPIだと単純にcurlで叩ける訳でもなく。
一応そういうツールもありますが、認証情報を追加して打ち込むの面倒臭いですし(そもそも暗号化してる認証情報を直で打ち込もうとしたら色々障害があるし)、
クライアント側にお願いしてリクエストにパラメータを一々追加して貰うのもコストとリスクが伴いますし。
また、以下のようにオプション指定して調査ファイルを最初から指定することも出来ますが、これだと指定ファイルを変更したいという時にRailsの再起動が必要ですし。
config.middleware.use Rack::Lineprof, profile: 'active_support/core_ext/string'どうも、開発環境で使うにはぼちぼちと不便な点があります(そもそもローカルだけで使うようなgemだったりするかもしれませんが)。
じゃあ、どうする?
モンキーパッチだ!!
モンキーパッチ
実際に負荷の計算と出力を制御しているのは、このファイルです。
require 'rblineprof'
require 'logger'
require 'term/ansicolor'
module Rack
  class Lineprof
    autoload :Sample, 'rack/lineprof/sample'
    autoload :Source, 'rack/lineprof/source'
    CONTEXT  = 0
    NOMINAL  = 1
    WARNING  = 2
    CRITICAL = 3
    attr_reader :app, :options
    def initialize app, options = {}
      @app, @options = app, options
    end
    def call env
      request = Rack::Request.new env
      matcher = request.params['lineprof'] || options[:profile]
      logger  = options[:logger] || ::Logger.new(STDOUT)
      return @app.call env unless matcher
      response = nil
      profile = lineprof(%r{#{matcher}}) { response = @app.call env }
      logger.debug Term::ANSIColor.blue("\n[Rack::Lineprof] #{'=' * 63}") + "\n\n" +
           format_profile(profile) + "\n"
      response
    end
    def format_profile profile
      sources = profile.map do |filename, samples|
        Source.new filename, samples, options
      end
      sources.map(&:format).compact.join "\n"
    end
  end
end端的に言えばリクエストのlineprofを参照してか、それかinitializeした時のオプション指定ファイルに対して負荷調査を仕掛け、そして結果を整形、ログ出力をしています。
これをコピーしてconfig/initializers/以下に置くか、適当な場所に置いてinitializersでrequireするようにするかして(これも本番環境では読み込まれないようにするとか工夫した方が良い)、ソースを上書いてしまいましょう。
あ、後、定数の上書きはwarningが出るので、以下の辺りはコメントアウトしておいた方が良いかもしれません。
 CONTEXT  = 0
    NOMINAL  = 1
    WARNING  = 2
    CRITICAL = 3そしてファイル指定やログ指定を動的に決定したいという時は、
 def call env
      request = Rack::Request.new env
      matcher = request.params['lineprof'] || options[:profile]
      logger  = options[:logger] || ::Logger.new(STDOUT)ここ辺りを、
  def call env
      request = Rack::Request.new env
      # RedisManagerはredis操作クラスということで
      survey_file_name = RedisManager.get_cache("survey_file_name")
      matcher =
        request.params['lineprof'] \
        || options[:profile] \
        || survey_file_name
      logger  =
        options[:logger] \
        || select_loggers(survey_file_name) \
        || ::Logger.new(STDOUT)
...
    def select_loggers(survey_file_name)
      ...
    endこんな感じに変えてしまって。
後はこのredisの中身を管理画面から弄れるようにしてしまえば、好きな時に好きなファイルを開発環境で調査出来るようになります。
……え? ここまでやったなら出力結果もサーバーに入ってtail -f とかするんじゃなくて、管理画面で見れるようにしたい?
出力したログの内容を管理画面からDLさせるようにするか、それともprofileの結果を別途保存しておいて、管理画面で見せるようにするか。
前者の方が簡単なので、それが出来るならそうした方が良いかと。
ただ、実装している時の自分はどうしてか後者を選んでました。
取り敢えず、format_profileメソッドで作られたログ出力用のものをhtml出力用にするには色々面倒だった事をお伝えしておきます。
