こころがホッコリー

ただイカしたRubyistになりたい人生だった。

会社の開発合宿で、任意のメソッド呼び出しを監視するgemを作ってきた話

現職の開発部では、半年に一度ぐらいのペースで、開発合宿を開催しています。
その中で、今回は「プロダクションコードを変更せず、任意のメソッド呼び出しを監視できるgem」を作成してきたので、簡単にその紹介をしたいと思います。 (まだ、rubygems.orgには登録していません)

開発合宿の様子について興味がある方は、会社の開発部ブログの方をご覧ください。

texta.pixta.jp

なぜ、任意のメソッド呼び出しを検出したいのか

なぜ、こんなgemを作ろうと思ったかと言いますと、率直に言えば、
自社のプロダクションコードに、もう使われていないであろうメソッドが多く存在していることを知ったためです。
「使われていないことを知っているなら消せばいいじゃないか?」という話になると思いますが、
Ruby動的言語なので、さっとコードを洗った程度では「どこからも呼ばれない」という確信は持てません。
もしかすると、メソッド呼び出しが動的に定義されているかもしれないからです。

gem作成の動機付けとなった記事

そんな時に出会ったのが、クラウドワークスさんのエンジニアブログにある以下の記事でした。

engineer.crowdworks.jp

上記記事の中で触れられている「方法3. 未使用な何かの削除」がまさに私が抱いていたモヤモヤへの解となるアプローチでした。
記事内の手法は、任意のメソッド呼び出しをアラウンドエイリアス(Railsなのでalias_method_chainを利用)でラップし、メソッド呼び出し時にはロギングするというものです。
こうすることで、本番運用の中でメソッド呼び出しを監視し、安心してメソッドの削除ができるようになります。

が、記事内で紹介されている手法では、1点気になることがありました。
それは、メソッド監視のためにプロダクションコードへの追加実装が必要な点です。
リファクタリング準備のためだけにプロダクションコードに手を加えるのは、草の根活動であればなかなか理解を得づらいのではないかと思います。
そこで、「プロダクションコードの外部から監視したいメソッドを指定できるgemを作れば便利ではないか?」と思い至りました。

今回作成したgem「okuribito」について

GitHub - muramurasan/okuribito

gemの名前:
 okuribito
gemの概要:
 未使用のメソッドかを判別するため、yamlファイルに監視したいメソッドを記述することができる。
 監視対象メソッドが呼ばれた際のアクションとして、「コンソール出力」、「Slack通知」、「ログファイルへの書き込み」を選択することができる。
 また、メソッドの監視開始日時はログファイルに記録しておくことができる。

導入方法

本gemはRailsに限ったgemではありませんが、説明の便宜上、Railsチュートリアルサンプルに導入するステップを例示したいと思います。

github.com

Gemfileの編集

Gemfileを編集し、

gem 'okuribito',  :github => 'muramurasan/okuribito'

と追加してから、bundle install を叩きます。
すると、

Using okuribito 0.1.0 from git://github.com/muramurasan/okuribito.git (at master@848a40a)

みたいな実行ログが出るので、これでOKです。
(本gemはまだrubygems.orgに登録していないため、GitHubから持ってきています)

監視対象のメソッドを設定

次に、監視対象のメソッドを、config/okuribito.yml というファイルに記述します。

User:
  - '#feed'
Micropost:
  - '.from_users_followed_by'

Rails起動後に、okuribitoを適用

次に、application.rb に以下のコードを追記し、Rails起動後に本gemが適用されるように仕込みます。

      class OkuribitoSetting < Rails::Railtie
        config.after_initialize do
          okuribito = Okuribito::OkuribitoPatch.new(
            {
              console: "back_trace",
              slack: "https://hooks.slack.com/services/xxxxxxxxx/xxxxxxxxxx/xxxxxxxxxxxxxxxxxxxxxxxx",
              logging: "log/okuribito/method_called.log",
              first_prepended: "log/okuribito/first_prepended.log"
            }
          )
          okuribito.apply("okuribito.yml")
        end
      end

上記コードにある通り、newする際にオプションをHashのパラメータで指定することができます。

  • console
    • 1行表示のシンプルな plane か、バックトレースを詳細に表示するback_trace を選べます。メソッド呼び出し検出時にコンソールに出力されます。
  • slack
    • slackの InComming Webhook のURLを指定することができます。メソッド呼び出し検出時にSlackに通知が行われます。
  • logging
    • ロギングするファイルのパスを指定できます。メソッド呼び出し検出時、呼出日時、メソッド名、直前のメソッドコールがロギングされます。
  • first_prepended
    • メソッドの監視開始日時を記録するログファイルのパスを指定できます。監視対象に投入された初回の日時のみ記録されます。

使ってみた結果

まず、Railsを起動します。 この時点で、監視開始日時の管理ログには User#feedMicropost.from_users_followed_by が追加されます。

2016-08-19 09:35:43 +0900,User#feed
2016-08-19 09:35:43 +0900,Micropost.from_users_followed_by

次に、それぞれのメソッドを通る、ログイン後のトップ画面にアクセスしてみると......

コンソールに詳細なバックトレースが出力されます。

#############################################################
# #<User:0x007feaa3b6e488> : feed is called.
#############################################################
/Users/ym/works/sample_app_rails_4/app/controllers/static_pages_controller.rb:6:in `home'
/Users/ym/.rbenv/versions/2.0.0-p647/lib/ruby/gems/2.0.0/gems/actionpack-4.0.8/lib/action_controller/metal/implicit_render.rb:4:in `send_action'
/Users/ym/.rbenv/versions/2.0.0-p647/lib/ruby/gems/2.0.0/gems/actionpack-4.0.8/lib/abstract_controller/base.rb:189:in `process_action'
/Users/ym/.rbenv/versions/2.0.0-p647/lib/ruby/gems/2.0.0/gems/actionpack-4.0.8/lib/action_controller/metal/rendering.rb:10:in `process_action'

... 省略 ...

#############################################################
# Micropost : from_users_followed_by is called.
#############################################################
/Users/ym/works/sample_app_rails_4/app/models/user.rb:27:in `feed'
/Users/ym/works/okuribito/lib/okuribito.rb:68:in `block in define_okuribito_patch'
/Users/ym/works/sample_app_rails_4/app/controllers/static_pages_controller.rb:6:in `home'

Slackにも通知されます。 f:id:muramurasan:20160819094716p:plain

ログファイルにも記録されています。

2016-08-19 09:45:30 +0900, #<User:0x007feaa3b6e488>#feed : /Users/ym/works/sample_app_rails_4/app/controllers/static_pages_controller.rb:6:in `home'
2016-08-19 09:45:31 +0900, Micropost.from_users_followed_by : /Users/ym/works/sample_app_rails_4/app/models/user.rb:27:in `feed'

実運用では、これらのメソッドはまだ使われていることがわかったので、監視対象から外していくことになります。

感想

荒削りですが、思ったよりも便利なgemができたのではないかと思います。
プロダクションコードの修正はgemの初期設定だけで、後は追加のyamlファイルを設置するだけなので、そんなに手間もありません。
ただ、監視したいメソッドが大量にある場合、逐一yamlに書くのはちょっと大変かも....。
この辺り、もっと便利にしていかないと、実用的なgemにはほど遠いのかな......と思います。

課題

  • Readme.md を整理する
  • 可能ならばテストを書く
  • rubygems に登録する
  • Railsからokuribitoを簡単に利用できるようにするgemを書く (okuribito-rails的な)
  • 呼び出し実績のあるメソッドを、yamlファイルから削除するコマンドを提供する
  • yamlファイルを書く手助けとなる機能を提供する

その他、いけていない点、バグ、こうしたらもっと便利になる等々ありましたらお寄せください。ひっそりお待ちしています。