この記事はElastic stack (Elasticsearch) Advent Calendar 2018の24日目の記事です。
アクセスログの分析などの用途でKibanaを使っていて、〇〇しようとしたら、Kibanaの画面が固まってしまったといった話を聞くことがあります。今日はそんなアンチパターンを紹介します。
先頭のワイルドカードを使ったクエリ
例: アクセスログでユーザーエージェントを表すフィールドに対して *GoogleBot*
Analyzeされてないフィールドに対して「〜を含む」という条件でフィルタしたいときに使ってしまいそうになりがちですが、先頭にワイルドカードがあると、Elasticsearchが知っているterm一つ一つについてマッチするか確認する必要があり遅いです。データが小規模ならよいですが、大規模なログを扱う時などは基本的に避けるべきです。
対策としては、Query Stringクエリのオプションには allow_leading_wildcard というものがあり、ここを false にすると先頭のワイルドカードが無効になります。Kibanaの設定画面にはこれをコントロールする項目があるので、あらかじめ無効にするのを検討してもいいかもしれません。
なお逆にワイルドカードを使ってもあまり負荷がかからないのは、十分にtermを絞り込めるような長さのprefixの後にワイルドカードを使った場合です。Elasticsearch (というかLucene) はtermを辞書順で管理しているので、特定のprefixを持つtermを列挙するのは得意です。
カーディナリティが非常に高い文字列型のフィールドに対するアグリゲーション
若干特殊なケースではあるのですが、紹介します。
例: アクセスログのRequest-URIのフィールドをbucketとしてvisualizeする
エンドポイント別にリクエストタイムなどを集計しようとしてやってしまうことがあります。といってもこのフィールドのカーディナリティが大して高くないうちは別に問題ありません。問題になるのは、Request-URIに含まれるクエリパラメータに、クライアント側でランダムに生成した一回限りの値が入っているような場合で、その時フィールドのカーディナリティはデータの量に比例した非常に高いものになる可能性があります。
といっても、なんだかよくわからないので検証コードを示します。
version: "3.5"
services:
elasticsearch:
image: docker.elastic.co/elasticsearch/elasticsearch-oss:6.5.1
volumes:
- esdata:/usr/share/elasticsearch/data
environment:
- "bootstrap.memory_lock=true"
- "ES_JAVA_OPTS=-Xms512m -Xmx512m"
ulimits:
memlock:
soft: -1
hard: -1
ports:
- "9200:9200"
kibana:
image: docker.elastic.co/kibana/kibana-oss:6.5.1
environment:
ELASTICSEARCH_URL: http://elasticsearch:9200
ports:
- "5601:5601"
depends_on:
- elasticsearch
volumes:
esdata:
driver: local
こんなComposeファイルを書いてローカルにElasticsearchとKibanaを立ち上げておき、以下のスクリプトで検証用のデータを投入します。1000万件入るようになっており、手元で実行に十数分かかりました。
from elasticsearch import Elasticsearch
from elasticsearch.helpers import bulk as es_bulk
from datetime import datetime
import random
import sys
settings = {
'index': {
'number_of_shards': 1,
'number_of_replicas': 0,
'refresh_interval': -1, # インデキシングを高速に行うため自動refreshは止める
},
}
mappings = {
'_doc': {
'properties': {
'uri': {'type': 'keyword'}, # Request-URI
'timestamp': {'type': 'date'},
},
'dynamic': 'strict',
},
}
index = 'huge_cardinality_test'
es = Elasticsearch(hosts='localhost:9200')
if es.indices.exists(index):
es.indices.delete(index)
es.indices.create(index, body={
'settings': settings,
'mappings': mappings,
})
def gen_random_docs(n):
for _ in range(n):
yield {
'_index': index,
'_type': '_doc',
'uri': f'/?_={random.randint(0, sys.maxsize)}',
'timestamp': datetime.utcnow().isoformat(),
}
num_of_docs = 10000000
es_bulk(es, gen_random_docs(num_of_docs))
es.indices.refresh(index)
極端ですが、クライアントが常に /?_=XXXXXX（XXXXXXの部分にランダムな数字が入る）のようにランダムなクエリパラメータをつけてリクエストしてくるような想定のアクセスログデータだと思ってください。この場合フィールドのカーディナリティはデータ数と同じです。
データを入れ終わったら、KibanaでDiscoverを開きます。サイドバーから uri フィールドのvisualizeのボタンを押します。
この時はちゃんと集計結果が出ます（全てのtermが1件ずつなので結果としてはあまり意味がないですが）。ちなみにこのとき /_nodes/stats/indices を叩いて取得した fielddata.memory_size_in_bytes の値は50MBほどでした。
さて次はデータ数の桁を一つ増やして1億件にしてみます。同様のアグリゲーションを行おうとすると……
elasticsearch_1 | java.lang.OutOfMemoryError: Java heap space
なお、起動時に環境変数 ES_JAVA_OPTS=-Xms512m -Xmx512m を渡してElasticsearchが使うヒープの大きさを512MBに設定しています。
さて、何が起きているのでしょうか。推測ですが巨大なglobal ordinalsの構築だと思っています。先にtermは辞書順で管理されていると書きましたが、これは具体的にはtermは辞書順の番号を振られて、内部的にはその番号で表現しているということです。こうした番号もしくはtermと番号のマッピングがordinalと呼ばれています。まずシャード内の各セグメントで管理されるordinalsがあり、それに対してglobal ordinalsは各セグメントのordinals同士のマッピングであり、こちらはオンデマンドでメモリ上に作成されます。例えばアグリゲーションを行うときにそのフィールドのglobal ordinalsの構築が走るのですが、それには全セグメントのordinalを参照する必要があり、また作成されるglobal ordinalsのサイズもユニークなtermの数に比例します。結果としてフィールドのカーディナリティに比例したメモリと計算が必要になり、フィールドのカーディナリティが異常に高いときには応答不能になってしまうのだと考えられます。また、global ordinalsの構築は、アグリゲーションの範囲によらずインデックス全体のtermに対して行われるため、たとえ集計期間を15分にとったところで、消費するリソースを抑えることはできないようです。
対策ですが、基本的にカーディナリティが高すぎるものにアグリゲーションを行なっても、あまり意味のある結果は得られにくいので、そもそもアグリゲーションを行わない、というところでしょうか。アグリゲーションが必要なら、何らかの前処理やデータの作成方法の工夫によりカーディナリティを抑えるのが有効です。例えば最初にあげたアクセスログの例だと、エンドポイントごとの集計が目的なら、そもそも集計で使いたいエンドポイントの識別情報をデータに含めておくか、もしくは最低限クエリパラメータを落としたパス情報だけを使う、などが考えられます。
おわりに
私が見聞きしたところだと、KibanaからElasticsearchクラスタ全体での応答の遅延を起こすようなクエリを送ってしまうパターンはだいたい上の2つにおさまっていました。ので、以上を踏まえて使ってもらうと安心かもしません。
ところで今日は会社のブログにもElasticsearchの利用事例で記事を書いたので、興味ある方はそちらもご覧ください。