splapiのアクセスログの可視化を始めてみた。 – return $lock;
導入にめちゃくちゃ苦労してしまったので、後で記事にしようと思います。
記事にしました。
前置き
Kibanaで可視化するにあたってnginxのアクセスログをltsv形式にしてfluentdで送出しています。
導入当初はt2.microインスタンス（Amazon EC2の無料枠）をログ収集サーバ（fluentd→elasticsearch）にした上で、Kibana 4を動かしていたのですが、以下の問題がありほぼまともに運用出来てない状態でした。
- kibanaがリソース不足（多分）で5時間と起動し続けられない
- elasticsearchがリソース不足（多分）で2日くらいすると落ちる（1日大体10万ドキュメント程度流し込まれる）
- elasticsearchが起動直後に即落ちするようになる。（多分リソース不足）
- fluentdが起動直後に即落ちするようになる。（多分リソース不足）
Kibanaのほうは使うたびに起動させればいいのでとりあえずどうにかなってたのですが、elasticsearchのほうがチューニングしても全く安定しない状態でした。（スワップ1GB増やした状態でヒープ固定で512mにしてたけどだめだった。）
ちなみに当初の構成はこんな感じでした。
困ったので、EC2の無料枠でどこまで出来るのか調べるのに「AWS クラウドサービス無料利用枠 | AWS」を見ていたらすごいことに気づきました。
Elasticsearch Service、無料枠あるのかよ！！！！！！（ないと思ったからEC2使ってた。）Prime Musicでキリンジのアルバムとファンタビジョンのサントラが聴けるのを知った時くらい驚きました。情報弱者はこういうところで世間と差がついていくのですね。
とりあえず構成を以下に変更して、Elasticsearch Service (ES)を使うことにしました。
今後のことを考えると、APPサーバとESの間にAPPサーバとは別の環境で動く収集用のfluentdサーバを置くべきなんだろうなとは思うのですが、elasticsearchが動かなくなったEC2インスタンスのfluentdも何故か即落ちしてしまうので諦めました。完全にインスタンスまるごとぶっ壊したわこれ。（インスタンスは廃棄した）
ログ送信側の設定
環境は以下。
- OS: CentOS 7
- fluentd: td-agent 0.12.20
nginxのログ設定
log_format ltsv 'time:$time_localt'
'host:$remote_addrt'
'request:$requestt'
'status:$statust'
'size:$body_bytes_sentt'
'referer:$http_referert'
'ua:$http_user_agentt'
'reqtime:$request_timet'
'upsttime:$upstream_response_time';
どこかの設定を参考にした気がするのですが失念しました…。Labeled Tab-separated Values (LTSV)に”Recommendations for labeling”の項目があるのを後から知ったのですが、もうelasticsearchにドキュメント流し込みまくってて手遅れな段階だったのでこのままの運用でいくことにしました。
注意点として、td-agentの実行ユーザ（デフォルトはtd-agent）がnginxのログを読めるようにパーミッション周りを変更しておく必要があります。logrotateを設定しているなら、logrotateの出力設定も変更しておかないと、ローテートしたタイミングでtd-agentがログを読めなくなってしまいます。（設定忘れててはまった。）
fluentd(td-agent)と、使用するプラグインのインストール
Installing Fluentd Using rpm Package | Fluentdを参照しています。
$sudo curl -L https://toolbelt.treasuredata.com/sh/install-redhat-td-agent2.sh | sh
$sudo td-agent-gem install fluent-plugin-elasticsearch
fluentdの設定
tailプラグインからログをltsv形式で読み込んだ後、数値・時刻部分をキャストしてelasticsearchに送出しています。キャスト周りはtail Input Plugin | Fluentdを参考にしています。
<source>
type tail
path /var/log/nginx/xxx/access.log
pos_file /var/log/td-agent/buffer/api.access.log.pos
format ltsv
time_format %d/%b/%Y:%H:%M:%S %z
types size:integer, status:integer, reqtime:float, upsttime:float, time:time
tag nginx.access
</source>
<match nginx.access>
type_name nginx
type elasticsearch
include_tag_key true
tag_key @log_name
host search-elasticsearch-(>_<).amazonaws.com
port 443
scheme https
logstash_format true
flush_interval 10s
retry_limit 5
buffer_type file
buffer_path /var/log/td-agent/buffer/casted.nginx.access.buffer
##############################################################
#!!! DO NOT SET THIS PROPERTY TO true FOR Amazon Elasticsearch Service !!!
#Elasticsearch service doesn't return addresses of nodes and Elasticsearch client
#fails to reload connections properly.
############################################################
reload_connections false
</match>
DO NOT SET…の部分ですが、設定しないと以下エラーが発生してelasticsearchにアクセスできなくなります。
2016-06-13 10:03:04 +0900 [warn]: temporarily failed to flush the buffer. next_retry=2016-06-13 10:03:05 +0900 error_class="Elasticsearch::Transport::Transport::Error" error="Cannot get new connection from pool." plugin_id="object:3fda5fb49af0"
2016-06-13 10:03:04 +0900 [warn]: /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/elasticsearch-transport-1.0.15/lib/elasticsearch/transport/transport/base.rb:193:in `perform_request'
2016-06-13 10:03:04 +0900 [warn]: /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/elasticsearch-transport-1.0.15/lib/elasticsearch/transport/transport/http/faraday.rb:20:in `perform_request'
2016-06-13 10:03:04 +0900 [warn]: /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/elasticsearch-transport-1.0.15/lib/elasticsearch/transport/client.rb:125:in `perform_request'
2016-06-13 10:03:04 +0900 [warn]: /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/elasticsearch-api-1.0.15/lib/elasticsearch/api/actions/bulk.rb:87:in `bulk'
2016-06-13 10:03:04 +0900 [warn]: /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/fluent-plugin-elasticsearch-1.5.0/lib/fluent/plugin/out_elasticsearch.rb:278:in `send'
2016-06-13 10:03:04 +0900 [warn]: /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/fluent-plugin-elasticsearch-1.5.0/lib/fluent/plugin/out_elasticsearch.rb:271:in `write'
2016-06-13 10:03:04 +0900 [warn]: /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/fluentd-0.12.20/lib/fluent/buffer.rb:345:in `write_chunk'
2016-06-13 10:03:04 +0900 [warn]: /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/fluentd-0.12.20/lib/fluent/buffer.rb:324:in `pop'
2016-06-13 10:03:04 +0900 [warn]: /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/fluentd-0.12.20/lib/fluent/output.rb:329:in `try_flush'
2016-06-13 10:03:04 +0900 [warn]: /opt/td-agent/embedded/lib/ruby/gems/2.1.0/gems/fluentd-0.12.20/lib/fluent/output.rb:140:in `run'
このエラーについての詳細は以下。
Elasitcsearch-ruby raises “Cannot get new connection from pool” error – Elasticsearch – Discuss Elasticsearch, Logstash and Kibana | Elastic
ええ…バグじゃねえのこれ…。
pos_fileとbuffer_pathの出力先は予め作成しておく必要がありました。詳しくはtailプラグインのドキュメントとelasticsearchプラグインのドキュメントを参照してください。
ログ受信側の設定
[新機能]Amazon Elasticsearch Serviceがリリースされました！ ｜ Developers.IO
この記事通りにセットアップすると10分後くらいに自動的にelasticsearchとkibana 4が使えるようになっています。すごいですね。ただし、無料枠で使用する場合、t2.microかつ、Single-AZ構成にする必要があります。
注意点としては、アクセスポリシーを再変更すると、ステータスがActiveになるのに10分くらいかかるのが結構罠です。（自分の端末のIPアドレス許可するの忘れてKibanaにアクセスできなくなったので変更した。）
私はIPベースでアクセス許可していますが、IAMベースでアクセスコントロールする場合、fluent-plugin-elasticsearchは使用できず、fluent-plugin-aws-elasticsearch-serviceを使用する必要があります。
fluent-plugin-aws-elasticsearch-service 導入時にハマった箇所 – Qiita
これ見て「めんどくさそう」という感想しか湧いてこなかったのでIPベースでいいやと思いました。
ちなみにindex名がlogstash-YYYY.MM.DD固定になる問題の回避策は上記Qiitaに記載があります。私は特に困ってないのでそのまま運用しました。
マッピングの設定
このまま受信するとUserAgentやリファラが謎文節で区切られてすこぶるわかりづらくなるので、お好みに応じてマッピング用のjsonをPUTする必要があります。私はこんな感じで設定しました。
{
"template":"logstash-*",
"mappings":{
"nginx":{
"properties":{
"host":{
"index":"not_analyzed",
"type":"string"
},
"request":{
"index":"not_analyzed",
"type":"string"
},
"ua":{
"index":"not_analyzed",
"type":"string"
},
"referer":{
"index":"not_analyzed",
"type":"string"
}
}
}
}
}
curl -X PUT https://search-elasticsearch-(>_<).amazonaws.com/_template/xxx --data @template.json
Kibanaで可視化した結果
splapiの1日のアクセスログのDiscover。予想してたけどステージ変更時はアクセス多くなりますね。
