目的

Kibana で Heroku アプリのログを可視化したい。ただし、レスポンスタイムとかは New Relic でも見れるので、ここではアプリが出力したらログを可視化する方法を紹介する。

また、今回、アプリからの出力を可能な限りに簡単にするために、アプリからは Heroku の STDOUT に出力するだけで、ログを Kibana サーバに送信できるようにしてみた。

具体的にはこう。（Ruby の場合）出力の形式は、Treasure Data addon の方法 を真似ている。

puts "@[tag.name] #{{'uid'=>123}.to_json}"

これで、tag.name が fluentd の tag 名に、それに続くJSON 文字列が送信するデータとして処理される。

環境

• Amazon EC2 上に Kibana サーバを構築
• OS はUbuntu 13.10
• td-agent と ElasticSearch は導入済み

タイトルで fluentd と書いたが、正確には td-agent を使っているので、fluentd を使っている人は適宜読み替えること。

ログデータの流れ

処理の概要は以下の通り。

Heroku -> (syslog drains) -> rsyslog -> (syslog file) -> Fluentd(in_tail, rewrite, parser, elasticsearch) -> ElasticSearch -> Kibana

1. Heroku のsyslog drains を利用して、Kibana サーバに syslog を送信
2. Kibana サーバに rsyslog サーバを立てて、Heroku からの syslog を受信して、ファイルに出力
3. Fluentd の in_tail 機能を利用して、ログを読み込み、rewrite, parserプラグインを利用して、ログの変形とフィルタリング
4. elasticsearchプラグインを利用して ElasticSearch にログを投入
5. Kibana で見る

Heroku の設定

Heroku のsyslog drains 機能を利用して、syslog を指定したサーバに送信する設定をする。Kibana サーバで 5140 ポートで rsyslog サーバを起動する場合。

$ heroku drains:add syslog://[kibana-server]:5140 -a [heroku-app-name]Successfully added syslog://[kibana-server]:5140

追加が完了したら、heroku drains コマンドで、drain ID を取得する。このd. で始まる drain ID は後で使うので、記録しておく。

$ heroku drains -a [heroku-app-name]syslog://[kibana-server]:5140 (d.XXXX)#                             ~~~~~~~~ ここが drain ID

参考：https://devcenter.heroku.com/articles/logging#syslog-drains

注意点としては、Kibana サーバを EC2 に立てている場合は、Elastic IP を設定した上で、PublicDNS をサーバ名として指定する必要があること。これは Heroku 側でAWS の Private Address として Look up できないといけない Heroku のセキュリティ上の仕様のため。

参考:https://devcenter.heroku.com/articles/logging#security-accessこの制限は今はない。

rsyslog の設定

TCP サーバの起動

Heroku はUDP ではなくTCP で syslog を送信してくるので、rsyslog でTCP サーバを起動する。/etc/rsyslog.conf を開いて、以下を追記（または、今ある要素をコメントアウト解除）

$ModLoad imtcp$InputTCPServerRun 5140 # ポート番号は heroku drains で設定したポートを指定。

ファイル作成権限の変更

デフォルトだと、syslog は root:adm に 0640 で作成されるので、fluentd から読み出すことができない。なので、ファイルの作成権限の変更を行います。同じく、/etc/rsyslog.conf の最後に以下を追記する。

$FileCreateMode 0644$DirCreateMode 0755

参考:http://y-ken.hatenablog.com/entry/fluentd-syslog-permission

ログファイルの振り分け

デフォルトだと、/var/log/syslog に heroku のログが出力されていまうのだが、これだと fluentd で in_tail しにくいので、これを別ファイルに振り分ける。ここでは/var/log/heroku に出力するようにしてみる。

/etc/rsyslog.d/40-heroku.conf という名前のファイルを作成し、以下の内容を記述。

if $hostname startswith '[heroku drain ID]' then /var/log/heroku& ~

1行目が振り分け設定。2行目が1行目で一致したログを後続の syslog に出力しないようにする設定。もし、複数の Heroku の syslog を受ける場合は、上記の2行をdrain IDを変えながら、繰り返して記述する。

RuleSet を使って、TCP で受け付けるデータのフィルタリングとかすると良いかも。（ここは調整中）http://www.rsyslog.com/doc/multi_ruleset.html

ログローテーションの設定

振り分け設定したログに対して、/etc/logrotate.d/rsyslog にログローテーションの設定をする。以下は daily で 7日間でローテーションする設定する例。

/var/log/heroku{        rotate 7        daily        missingok        notifempty        delaycompress        compress        postrotate                reload rsyslog >/dev/null 2>&1 || true        endscript}

rsyslog を再起動

全ての設定を保存したら、rsyslog を再起動。

$ sudo service rsyslog restart

AWS security group の設定

AWS の security group の設定で、EC2インスタンスに紐付いた security group のTCP 5140 ポートを開放する設定をする。Management Console からでも良いし、awscli で以下のようにしても良い。

$ aws ec2 authorize-security-group-ingress --group-name MySecurityGroup --protocol tcp --port 5140 --cidr 0.0.0.0/32

AWSじゃない人は、Firewallの設定で同様に 5140 ポートを開放する。

正しく設定できれば、この時点で/var/log/heroku に heroku の syslog が出力されているはず。tailして確認してみる。

$ tail -f /var/log/herokuFeb  2 03:41:32 [drain ID] app[web.`] Started GET "/XXX" for XXX.XXX.XXX.XXX at 2014-02-02 03:41:32 +0000

こんな感じのログが見えれば、設定は完了。

fluentd の設定

必要な gem のインストール

td-agentの場合は、fluent-gem を使うように注意する。

$ fluent-gem install fluent-plugin-rewrite$ fluent-gem install fluent-plugin-parser$ fluent-gem install fluent-plugin-elasticsearch

td-agent.conf の設定

処理の概要は、以下の通り。

1. in_tail で heroku の syslog を解析
2. fluent-plugin-rewrite でアプリログと Heroku のログを振り分け
3. fluent-plugin-parser でJSON データの解析
4. fluent-plugin-elasticesearch で ElasticSearch に出力

実際の/etc/td-agent/td-agent.conf の設定はこう。

<source>  type tail  path /var/log/heroku  pos_file /var/log/td-agent/posfile_heroku.pos  format /^(?<time>[^ ]*\s+[^ ]*\s+[^ ]*) (?<host>[^ ]*) (?<ident>[a-zA-Z0-9_\/\.\-]*)(?:\[(?<pid>[a-zA-Z0-9\.]+)\])? *(?<message>.*)$/  time_format %b %d %H:%M:%S  tag heroku.syslog</source># アプリログとHerokuが出力するログを振り分け<match heroku.syslog>  type rewrite  <rule>    key message    pattern ^@\[([a-zA-Z0-9_\.]+)\]\s+.*$    append_to_tag true    fallback others  </rule>  <rule>    key message    pattern ^@\[[a-zA-Z0-9_\.]+\]\s+(.*)$    replace \1  </rule></match># アプリログ以外は読み捨て<match heroku.syslog.others>  type null</match># アプリログの処理# ここでは @[app.XXX] JSON と出力していることを想定# JSON データは message プロパティに文字列として格納されている<match heroku.syslog.app.**>  type parser  remove_prefix heroku.syslog  key_name message  format json  reserve_data true</match># ElasticSearch に出力<match app.**>  type elasticsearch  type_name app  include_tag_key true  tag_key @log_name  host localhost  port 9200  logstash_format true  flush_interval 3s</match>

再起動

設定を保存したら、fluentd (td-agent) を再起動。

$ sudo service td-agent restart

しばらくすると、Kibana でデータが見えるようになる。楽しい！