Thursday, July 21, 2016

NemakiWareでEFKスタックを立てました

こんにちは。linzhixingです。

文書管理製品NemakiWareも、開発だけでなく保守運用フェーズが増えてきたため、ログの収集・分析にEFKスタック(今更感)を立ててみました。とくにクラウドサービスとしてNemakiWareを提供する場合、CMIS規格に沿ってマルチリポジトリ=マルチテナントのように扱うケースがあるので、ログをリポジトリごと(顧客ごと)に分けて即時に分析したいというニーズがあります。

EFKスタック(ElasticSearch, fluentd, Kibana)の組み合わせで、
- fluentd によりNemakiWareからログをリアルタイムでElasticSearchに送信
- ElasticSearchに登録されたログをKibanaにより様々な切り口でビジュアライズ
します。

@Ubuntu14.04
NemakiWare 2.4(?), td-agent 0.12.20,

@ログ取得用の環境
ElasticSearch 2.3.4, Kibana 4.5.2
を使用します。

(NemakiWareの現在のバージョンは2.3.15で、ここではログ出力内容をエンハンスしたバージョンを使用していますが、この記事の内容には影響ありません。エンハンスは次期リリースに含められる予定です)

細かい設定はいくらでもできますが、世の中に解説記事は溢れているので、
ここではひとまず最短でハマらずにログ収集・分析ができること、を目指します。

NemakiWare 

NemakiWareをUbuntuにインストールします。
https://github.com/aegif/NemakiWare/releases

こんな感じのログが出るようになる予定です。
{"@timestamp":"2016-07-15T08:49:58.414+09:00","@version":1,"thread_name":"http-nio-8080-exec-12","level":"INFO","message":{"uuid":"56e06eea-e70c-4d4f-bb3e-ad60f955cbcc","repo":"bedroom","user":"admin","when":"completed","time":12519,"method":"getChildren","input":{"folderId":"c0a29c9e5a4f28f3117cc6edada56c39"},"output":{"num":100,"hasMoreItems":false,"totalNum":100}}}

リポジトリやユーザだけでなく、処理にかかった時間やメソッドの入出力値も取ることができます。

fluentd

fluentd自体はRubyのgemとして提供されていますが、特にこだわりがなければRubyインタプリタ等も同梱されていてapt-getやyumでインストールできるtd-agentを使います。

# td-agentのインストール
http://docs.fluentd.org/articles/install-by-deb
curl -L https://td-toolbelt.herokuapp.com/sh/install-ubuntu-trusty-td-agent2.sh | sh

# fluent-plugin-elasticsearchのインストール
(fluentdにはfluent-gemでインストールできるたくさんのプラグインがあります)
sudo /opt/td-agent/embedded/bin/fluent-gem install fluent-plugin-elasticsearch

# NemakiWareからElasticSearchへの転送設定
/etc/td-agent/td-agent.confを編集します。
詳しくは説明しませんが、
- <source>でNemakiWareのログをtailで監視し、tagを付けて<match>に渡す
  type jsonにより、ログの持つタイムスタンプやログレベルといった情報がjson形式で解釈されます 。
  ログメッセージ自体もNemakiWareによりjson形式で出力されている部分も含めて、全体がjsonになります。
  その結果、ElasticSearchやKibanaで、jsonのフィールド(message.input.folderId 等)構造にそって、そのまま検索することができます。
- tagが一致する<match>が実行される
  さきほどインストールしたfluent-plugin-elasticsearchプラグインが利用されています。
  Kibanaともともと相性がよいLogstash形式を指定しておきます。

<source>
  type tail
  path /opt/NemakiWare/apache-tomcat-8.0.28/logs/nemakicore.log
  pos_file /tmp/fluentd_nemaki_core_pos
  format json
  tag nemaki.core
</source>

<match nemaki.core>
  type elasticsearch
  logstash_format true
  logstash_prefix logstash
  # ElasticSearchのホストに書き換えてください
  host xxx.xxx.xxx.xxx
  port 9200
  type_name nemaki-core-log
</match>

#td-agentを再起動して設定を反映
sudo service td-agent restart

ElasticSearch

ElasticSearchとKibanaは、ログの収集・分析用ですので、NemakiWare + td-agentとは別インスタンスに立てます。
 
適当にインストールしてください。(適当)
https://www.elastic.co/guide/en/elasticsearch/reference/current/setup-repositories.html 
http://qiita.com/hana_moto/items/762aae6b8f2a93d176d2
http://qiita.com/inouet/items/6276c5a08c4fe5eecdb5

localhost:9200にアクセスして、jsonのメッセージが返ってくれば正常に起動しています。

UIとしてHEADをインストールしてもよいかもしれません。
sudo /usr/share/elasticsearch/bin/plugin install mobz/elasticsearch-head

# 設定
- 外部への公開
デフォルトではElasticSearchのホストはlocalhostにバインドされており、そのままでは外部から接続できません。
/etc/elasticsearch/elasticsearch.ymlの"network.host"で、IPアドレス外部への公開先を指定できます。
同じインスタンス上にあるKibanaだけを外部公開する場合はlocalhostのみで構いませんが、ElasticSearchもUIで見たいとか、Kibanaが更に別インスタンスである場合には、外部に公開するよう設定します。
ここではElasticSearchの中身を外から覗きたかったため、簡単のため0.0.0.0としています。

-マッピング
ログの項目(タイムスタンプなど)のインデクスへのマッピングとして、項目の値型やアナライズをするかどうか等は、事前に決めておくこともできますし、マッピングを変更するにはインデクスの作り直しが必要になるのでそのほうが望ましい場合もありますが、ここでは何もマッピング情報を定義せず、ElasticSearchに最初に送られたログデータにより自動的にマッピング情報を認識してもらいます。

幸い、Logstash形式を指定しているので、ログのインデクスはデフォルトでは日次で新しく立てられています。ログの内容が変わったりマッピングを変更したい場合は、次の日のインデクスから変更を適用することができます。

新しいマッピングフィールドが追加される分にはインデクスの再作成は必要ありません。
NemakiWareが出力するjson形式のログは、メソッドの入出力内容を細かく制御できるので、今までログに出していなかった引数をあらたに出すようにした場合、とくに何もしなくても、ElasticSearchやKibanaでそのフィールドにより検索することができます。

Kibana

適当にインストールしてください。(適当)
公式 https://www.elastic.co/jp/downloads/kibana からwgetして展開するか、
リポジトリを登録してパッケージからインストールすることができます。
http://qiita.com/windows222/items/57423a420d57399cbc3e#kibana

/opt/kibana/config/kibana.ymlのelasticsearch.urlに、ElasticSearchのURLを指定します。ここでは同一インスタンスになります。

sh ./opt/kibana/bin/kibana もしくは自動起動の設定をして、Kibanaを起動します。
http://localhost:5601にアクセスしてKibanaのぺージが表示されれば、正常起動しています。
 
# Out of Memory対策
Kibanaを素のままで動かしていると、そのうちOut of Memoryエラーで、そのインスタンス全体がにっちもさっちも動かなくなります。(メモリが潤沢にある場合は大丈夫なのかもしれませんが、2GB程度だと死にます)
原因は
http://mnatsu31.hatenablog.com/entry/2015/12/14/154427

Node.jsのv8エンジンがメモリを無制限に消費するためだそうです。
起動スクリプト本体である/opt/kibana/bin/kibanaファイルを編集して、Node.jsに対してオプションを外から渡せるようにしてあげましょう。

/opt/kibana/bin/kibanaファイル
-exec "${NODE}" "${DIR}/src/cli" ${@}
+exec "${NODE}" $NODE_OPTIONS "${DIR}/src/cli" ${@}
 
と編集した上で、
 
NODE_OPTIONS="--max-old-space-size=250" /opt/kibana/bin/kibana
により起動します。
 
# ElasticSearchからデータを取得していることの確認
画面上部ナビゲーションバーのDiscoverで、タイムスタンプごとの単純なCount数ヒストグラムと、そのソースになっているjsonログデータが確認できます。
NemakiWare固有のログのjsonフィールドも認識されています。
  
 # Kibanaで表示するグラフの設定
Kibanaには、ElasticSearchに保存されたログデータを検索して、グラフとして表示する機能が充実しています。
画面上部ナビゲーションバーのVisualizeから、作成するグラフの種類を選びます。

特にsaved searchを作成していないので、From a new searchを選択します。

左カラムで、X軸(値を集計するための切り口=バケット)とY軸(集計された値=メトリクス。CountやAverage等)を指定します。


ここでは単純に、Y軸にはログの件数(Count)を指定しつつ、X軸にはタイムスタンプに加えて各リポジトリごとにY軸の値を分解するようSplit Linesをサブバケットとして追加してあります。
グラフ右側に、アクセスのあったリポジトリが数種類表示されており、折れ線グラフもリポジトリごとに色分けされています。

X軸を工夫してCMISメソッドごとの切り口を追加し、Y軸を工夫してログ件数のかわりに平均処理時間をグラフにする、ということもできるようになります。


今回はここまでです。
主にKibanaによる可視化をゴールとして最短で進みましたが、せっかくfluentdを使っているので、保守運用のうえで必要になる各種ミドルウェアからのログも集約し、アプリ側のログとKibana上で突き合わせられるようにしたいところです。
機会があれば、また。

まとめ

- EFKスタックをインストールした。
- 次期NemakiWareの新しいjson形式ログにより、リアルタイムで様々な切り口によるログ分析が可能になった。ノーモア目検。