Kibana用途でElasticsearchを使う時の高負荷対策TIPS #Elasticsearch

これは Elasticsearch Advent Calendar 2015 8日目の記事です。

ログの可視化ツールとしてKibanaを使っている中で、Elasticsearch運用として色々と得られた知見を書きたいと思います。
Elasticsearchは、ライトな環境だったら特にチューニングなく安定してますがある程度ドキュメント数が積まれてくると、色々苦労があるなという印象です。
ここに書かれているのは、事情がありシングル構成で頑張った話なので、クラスタ組んでスケールするとこんな悩みはないのかもです。
でも、ログは運用系に入るのでそんなにコストかけれるとこはないのではという個人的な所感。

ラインナップとしては、下記のような感じです。

Kibana経由で重たいクエリが投げられると負荷高すぎて泣いた話
高負荷対策として、fielddata_cacheをディスクに逃がす方法
fluentdのプラグインからデータ投入してる時の、インデックスローテートの話(9:00前にKibana上でデータが見えなくなる)
まとめというか感想

↓こんな感じのグラフの裏側で色々苦労した話です。

今回の話のベース環境

Elasticsearch 1.5.2
Kibana3,4併用
サーバリソース Mem:32G(HEAPサイズは16G) CPU:24LP Disk:1krpmHDD
Elasticsearchの総ドキュメント数 15億doc

Kibanaの用途についても軽く書いておくと、弊社では下記のような使い分けをしています。
- Kibana3は主に、アクセスログとアプリケーションログをビジュアル的に可視化(良くある)
- Kibana4は、キーワード検索や大文字検索が出来るので、検索用途

1. Kibana経由で重たいクエリが投げられると負荷高すぎて泣いた話

うちの環境だと、アクセスログやアプリケーションログを各々1ヶ月くらいずつインデックスしてました。(1INDEXあたり、500万〜2000万docでサイズは様々)

標準としてKibanaで作っているモニタは1日だったり長くてもtime_filterを1週間くらいにしているので、5秒更新とかでリクエストが飛んできても耐えれる構成でした。

でも、中にはtime_filterを1ヶ月にして熱いLuceneのクエリを書いているメンバもいて、そんなリクエストが1インデックス2000万docくらいあるインデックスに対して飛んで来ると大抵下記のエラーが出ます。

例えば、主要パブリッククラウドのIPをレンジでクエリに書いて各業者からの流量を可視化するモニタとか!

こうなると、JAVAのHEAPサイズが一杯一杯になりリクエストを受付けなくなるので、下記のようにfielddata_cacheをクリアするという辛い運用をしていました。

$ curl -XPOST 'http://localhost:9200/_cache/clear' -d '{ "fielddata": "true" }'
{"_shards":{"total":1430,"successful":715,"failed":0}}

色々調べてわかったのが、Elasticsearchはキャッシュ機構としてfielddata_cacheをメモリに持ちなおかつデフォルト無制限らしいという事でした。(2.x系からは、後に説明するdoc_valuesが、デフォルトになるのでファイルシステムキャッシュを使いHEAPは逼迫しないように変更されています。)
定期的にKibanaからアクセス出来なくなる原因は、fielddata_cacheが一杯になるタイミングと判明。
辛いクエリがいつやってくるかわからないので、60分毎にgcするようにして、HEAPの30%にサイズを制限することでつかの間の安定を得ることが出来ました。
かなり、パッチ的な運用ですが、効果は絶大というかうちの環境でいうと挙動はかなり落ち着きました。

elasticsearch.yml

indices.fielddata.cache.expire: 60m #default -1
indices.fielddata.cache.size: 30% #default 無限

定期的に下記のAPIを叩き、メモリ大丈夫かを確認する日々を過ごしていました。。

$ curl -XGET 'http://localhost:9200/_stats/fielddata/?fields=field1,field2&pretty'

でも、それでもたまにFullGCが発生したり(30秒くらいアクセスできなくなる。。。)して、メモリが辛かったので、twitter上で @johtani　に教えてもらったdoc_valuesを試してみました。

2. 高負荷対策として、fielddata_cacheをディスクに逃がす方法

始めに、書きますがこの対応を入れてからKibanaが高負荷で落ちるというような事象がなくなりました。

2.x系からはデフォルトらしいですし、Elasticsearch運用でメモリまわりの悩みを抱えている方がいたらオススメです。

設定は、簡単で、だいたいログ投入だとfluentdやlogstashを使ってデイリーでインデックスを作っていると思うので、対象のインデックスに対して下記のような感じでテンプレートを当てていくだけで、翌日のインデックス作成時からdoc_valuesが適用されます。

"doc_values": true

※上記オプションを指定出来るのは、Stringだとnot_analyzed(分かち書きなし)のフィールドだけなのでご注意下さい。(date,integerはOK)自分自身、analyzeしているフィールドにも効くようなテンプレートを適用して、翌日インデックス作成されずあせるような事も経験したので。。。

テンプレートのサンプル

{
  "template" : "xxx_access_log*",
  "order" : "4",
  "mappings" : {
    "_default_" : {
      "_source" : { "compress":true},
        "dynamic_templates" : [{ "string_template":{ "match":"*" , "mapping":{"type": "string", "index": "not_analyzed", "doc_values": true},"match_mapping_type" : "string"}}],
      "properties": {
        "sc-status" : { "type":"integer", "doc_values": true },
        "@timestamp" : { "type":"date", "doc_values": true },
        "c_ip" : { "type":"multi_field",
          "fields":{
            "c_ip":{ "type":"string","index":"not_analyzed", "doc_values": true},
            "iptype":{ "type":"ip", "doc_values": true}
          }
        }
      }
    }
  }
}

適用は下記のように、

#weblog_templateというテンプレートを登録
$ curl -XPUT localhost:9200/_template/weblog_template -d "`cat ~/template1.json`"
#下記コマンドでweblog_templateの中身を確認し意図したものが適用されてるか確認
$ curl -XGET "localhost:9200/_template/weblog_template?pretty"

当然過去のインデックスには適用されないわけで、すぐに効果は出ませんでしたが、1週間くらいするとelasticsearch.logに下記のようなoldGCのログ出現がほぼなくなりました。(0になったわけではないですが。。。)

[WARN ][monitor.jvm              ] [logsrv1] [gc][old][1977709][8699] duration [37.8s], collections [1]/[39.6s], total [37.8s]/[37.4m], memory [14.3gb]->[13.2gb]/[15.8gb], all_pools {[young] [4.6mb]->[199.8mb]/[1.1gb]}{[survivor] [149.7mb]->[0b]/[149.7mb]}{[old] [14.1gb]->[13gb]/[14.5gb]}

1.2の対応で、不安定だったKibanaからのアクセスが劇的に改善したので、同じような悩みを持たれている方がいたら是非試してみることをオススメです。

まぁ、極論を言うとメモリを増設してMAXの32G JVMのHEAPに割り当てればこの規模であれば問題なくさばけるのかもしれませんが、今回はオンプレ環境だったこともあり、色々悩みました。

3.fluentdのプラグインからデータ投入してる時の、インデックスのローテートの話(9:00前にKibana上でデータが見えなくなる)

これは、自分自身の失敗談なのですが、fluentdからElasticsearchにデータインポートしているところである設定を変えたところ翌朝、kibanaに何も表示されなくなったという事件がありました。。

fluent-plugin-elasticsearchで、logstash形式のインデックスを作っているとデフォルトUTC 0時にローテート行われるので、JSTでいう09:00にインデックスのローテートが行われます。何となく気持ち悪かった(どうせならJST 00:00でローテートしたい)ので、下記オプションでlocaltimeでローテート出来ると知り、下記オプションを入れました。

utc_index false

すると、翌朝(09:00以前)kibanaにデータが表示されないという事件が発生しました。

原因を調べてみると、

要約

Kibana上で検索をした場合、実際にElasticsearchにはUTC変換してリクエストを投げる(検索対象インデックスはUTC変換された時間を基に出る)為、localtimeでインデックスをローテートするとJSTでいう00:00:00〜09:00:00の間データがひっかからなくなる。

例えば

kibanaで入れた検索条件:20151008T07:00:00+0900(本当は20151008_xxxインデックスから検索してほしい)
↓
実際のリクエスト:20151007T23:00:00+0900(UTCだから20151007_xxxインデックスに検索にいく)
→kibanaから見るデータはJST変換して出てくるが、20151007_xxxインデックスには、もちろんそのデータはないのでデータが出てこない。。。
(JSTでローテートした20151007_xxxインデックスにあるのは、UTC 20151006 15:00:00〜UTC 20151007 14:59:59)までのデータ。。

kibanaから見るという用途であれば、utc_index falseはやめたほうがいいという教訓を得ました。

4. まとめというか感想

Kibanaのグラフは素敵で、見えてなかったものを見える化すること大事
kibana4は、検索用途としては重宝するが、色とか含めグラフ用途だとまだいまいちなイメージ
Elasticsearchというか、JVMのヒープ問題は辛い。。
開発者は時に容赦無いクエリを投げてくるw
Elasticsearchのドキュメント量は、ちゃんと調整すること。(16G HEAP割り当てで、15億docくらいが限界)
あくまでも、Elasticsearchはログ用途ならリアルタイムデータをみるツールにした方がいい※長期は、BigQueryとか他のツールに任せる！
※定期的な削除は、elasticsearch-curatorを使って簡単に時系列インデックスを運用するとかでやると楽