Sinatra (Rack) のアクセスログをMongoDBに吐き出してみる

# はじめに
昨日は[ExpressのアクセスログをMongoDBに吐き出してみる](http://qiita.com/toyoshim/items/f517f95b94859815a63b)実験をしたわけですが、Sinatraで動いてるホストも10以上ありまして。インスタンス的にはExpressの方が多いのですが、ホスト的にはSinatraが一番多いんですね（Sinatraにvirtual host対応させてます）。なので、引き続きSinatraのアクセスログについて調査、MongoDBに吐き出せるようにしてみました。GitHubにて[Ramolog](https://github.com/toyoshim/ramolog)で公開してあります。

# Sinatraのアクセスログ介入
## 概要
SinatraのアクセスログはRack側で対処するのが正しそうです。RackにはCommonLoggerというのがあって、クラシックスタイルではこいつがデフォルトで動いています。モジュールスタイルでも`enable :logging`で動き出すのがこれ。

Rackの層で置き換えれば良いのだな、とわかって検索すると、一行入魂さんの[MongoDBにアクセスログを取るRack Middleware](http://aoyagikouhei.blog8.fc2.com/blog-entry-204.html)というエントリを見つけました。そのものズバリで基本的な流れはそのまま使えそうです。フォーマットだけ前回作ったExpress/Node.js版のmomologに揃えて、最終的にはRubygems化する事にしました。クラウドで運用してると、どうでも良いコードでもパッケージ化するモチベーションが湧くのが面倒なところでもあり、またメリットでもありますね。

## 実装
call(env)を適切に実装してあげればOK。実際のリクエストはコンストラクタの第一引数に渡ってくるインスタンスが処理するので、そいつを呼んでstatus、header、bodyを取得します。こいつらは自分自身も呼び出し元にそっくりそのまま返してあげる必要があります。

```rb
class MyLogger
  def initialize(app)
    @app = app
  end

  def call(env)
    status, header, body = @app.call(env)
    # ここで好き勝手ログを書き出す
    [status, header, body]
  end
end
```

あとは

```rb
require 'sinatra'

configure do
  use MyLogger
end
```

これだけで置き換えられる。楽ちん。

## ハマり場所

### Rack::Request or env
一行入魂さんのように`req = Rack::Request.new(env)`してしまって`req`経由で情報を集めるのも手なのですが、`Rack::Request#accept_language`なんかはパースされた結果が配列で格納されてたりするのですが、すでにExpressの方では生データを吐き出していたので、それだったらと`env['HTTP_ACCEPT_LANGUAGE']`をそのまま使う事にしました。

### Content-Length
レスポンス系の情報は`@app.call(env)`から返ってきた`header`を使うことになります。`header['Content-Length']`で取れるんですが、ないこともあるので`header['Content-Length'] or '-'`とかする必要があります。僕の場合はContent-Lengthは数値として格納していたので`(header['Content-Length'] or '-1').to_i`で存在しない時は`-1`です。

### REMOTE_ADDR
HerokuとかCloud9で実行してるとREMOTE_ADDRにはフロントエンドサーバのインターナルアドレスなんかが入ってたりしますね。なので、HTTP_X_FORWARDED_FORを使ってオリジナルのREMOTE_ADDRを辿る処理を追加しました。これ、Express版では対処できてなかったかも。後で対策考えないと……。

HTTP_X_FORWARDED_FORは複数回ルーティングされてきた場合にはカンマ区切りで複数のアドレスが入ってくるので`env['HTTP_X_FORWARDED_FOR'].split(',')[-1]`です。

# RubyGems化
gems化についてはクラスメソッドさんの[Rubygemsでライブラリを公開したので、手順をまとめてみた](http://dev.classmethod.jp/server-side/language/how-to-publish-rubygems/)を参考にしました。

credentialをcurlで取ってくる方法が紹介されてたんですが、情報が最新かわからなかったので、別の方法を取ることにしました。とりあえず気にせずにリリースを試みます。

```shell-session
toyoshim:~/workspace/thnet/ramolog (master) $ bundle exec rake release
gem build -V '/home/ubuntu/workspace/thnet/ramolog/ramolog.gemspec' 2>&1
ramolog 0.1.0 built to pkg/ramolog-0.1.0.gem.
git diff --exit-code 2>&1
git diff-index --quiet --cached HEAD 2>&1
git tag 2>&1
git tag -a -m "Version 0.1.0" v0.1.0 2>&1
Tagged v0.1.0.
git push  2>&1
git push  --tags 2>&1
Pushed git commits and tags.
rake aborted!
Your rubygems.org credentials aren't set. Run `gem push` to set them.
/usr/local/rvm/gems/ruby-2.2.1@global/gems/bundler-1.8.4/lib/bundler/gem_helper.rb:92:in `rubygem_push'
/usr/local/rvm/gems/ruby-2.2.1@global/gems/bundler-1.8.4/lib/bundler/gem_helper.rb:62:in `block in install'
Tasks: TOP => release => release:rubygem_push
(See full trace by running task with --trace)
```

ローカルにコミットしてないファイルがあると、ここで止まります。また、ログにあるように適切なtag付けやGitHubへのpushは勝手にやってくれます。

Gemfileの妥当性もチェックされるので、ポカミスとか見つけてくれる可能性もあります。私の場合、残念なtypoを指摘されて[恥ずかしいcommit](https://github.com/toyoshim/ramolog/commit/cf4032de0cfe48fc0141aaf5bb0b559525f270ab)が入りました。

ここで油断してたんですが、gemspecの方のdependencyはチェックされないんですね（両方に定義が必要なことに気づいておらず、忘れたまま0.1.0をreleaseしてしまい、慌てて修正版の0.1.1をpushした）。

で、最後のabort。`gem push`で設定できると言っているので従います。

```
toyoshim:~/workspace/thnet/ramolog (master) $ gem push
Enter your RubyGems.org credentials.
Don't have an account yet? Create one at https://rubygems.org/sign_up
   Email:   toyoshim@gmail.com
Password:   

Signed in.
ERROR:  While executing gem ... (Gem::CommandLineError)
    Please specify a gem name on the command line (e.g. gem build GEMNAME)
```

最後はエラーですが`Signed in.`なのでOKでしょう（この辺り、いつも雑です）。もう一度releaseを実行してみます。

```
toyoshim:~/workspace/thnet/ramolog (master) $ bundle exec rake release
gem build -V '/home/ubuntu/workspace/thnet/ramolog/ramolog.gemspec' 2>&1
ramolog 0.1.0 built to pkg/ramolog-0.1.0.gem.
git diff --exit-code 2>&1
git diff-index --quiet --cached HEAD 2>&1
git tag 2>&1
Tag v0.1.0 has already been created.
gem push '/home/ubuntu/workspace/thnet/ramolog/pkg/ramolog-0.1.0.gem' 2>&1
Pushed ramolog 0.1.0 to rubygems.org.
```

[成功](https://rubygems.org/gems/ramolog)。dependencyの記述が不完全だった0.1.0は`gem yank ramolog -v 0.1.0`で公開停止。これで一段落かな？

# まとめ
Sinatraを含めたRackベースのフレームワークから、アクセスログをMongoDBに向けて吐き出すモジュールを作り、Rubygemsに登録してみました。それなりに使われているフレームワークでも、意外に小さくまとまっていて、ログの置き換えくらいだったら数十行のコードでできちゃうのは嬉しいです。気軽にRubygems化しちゃえば、後はHerokuの各インスタンスに対して数行の修正を入れるだけで済みますし。

# 追記：おまけ
Rack層で仕込むのでRailsでもそのまま動きますね。

```rb:Gemfile
...
gem "ramolog", "0.1.1"
...
```

```rb:config.ru
require 'ramolog'
use Ramolog::Logger, ENV['MONGOLAB_URI'], 'log'

# 以下、自分で使ってるRedMineの元々の設定
require ::File.expand_path('../config/environment',  __FILE__)
run RedmineApp::Application
```