はじめに
Splunk に限らず、コンピュータ上で動くアプリケーションのパフォーマンスには様々な影響要因があります。一般的には CPU、メモリ、ディスク I/O、ネットワーク I/O などが挙げられると思いますが、今日はその中でも CPU をクローズアップして Splunk の性能にどう影響するのかを考えてみたいと思います。
Splunk の代表的なコンポーネントには Search Head と Indexer があります。特に Splunk のパフォーマンスを考えるときには Indexer の負荷に注目する必要があります。実際、性能面に問題を抱えている環境を見ると Indexer の負荷が問題になっているケースが多いようです。Indexer はデータの取り込みと検索という 2 つの仕事をこなしていますが、どのように CPU を使っているのか、少し詳しく説明します。
データ取り込み
まず、データの取り込みについて見てみましょう。データの取り込みは一連のパイプライン処理により行われています。パイプラインの中にはいくつかの工程がありますが、その中でも代表的な工程として以下の 4 つがあります。
- パーシング
データの文字コードを UTF-8 に統一し、改行などの処理を行う - アグリゲーション
複数行で構成されるイベントの整形およびタイムスタンプの抽出を行う - タイピング
インデックス時のフィールドの抽出を行う - インデックス
イベントのインデックスへの書き込み、または次のインスタンスへの転送を行う
他にも細かな工程があったり、Splunk Enterprise と Splunk Cloud では少し違ったりといったことはありますが、上記の 4 つが最も負荷がかかる処理になります。各工程はキューでつながっており、シリアルにそれぞれ独立したスレッドで実行されます。Indexer ではデータ取り込みのパイプライン数を設定することができますが、パイプラインが 1 つの場合、データ取り込みの負荷が高い Indexer では 4 つの CPU が利用される形になります。
Splunk Cloud ではデータパイプラインが 2 つ設定されているので、データ取り込み負荷が高い場合には最大 8 個の CPU がデータ取り込みに使用されることになりますが、別途ワークロードマネージャーによりデータ取り込みとサーチに使われる割合が決定されており、すべての CPU がデータ取り込みに使われることがないようになっています。
サーチ
次に、サーチについてみてみます。サブサーチなどを含まない通常のサーチは、原則 SPL の先頭からシリアルに処理をされるため、どんなに複雑な SPL であっても 1 つの CPU しか使いません。よく、Splunk のサーチは実行中 1 CPU を占有する、といったような話を耳にすることがありますが、それは正しくなく、サーチの実行中には CPU を使う瞬間もあれば、ディスクやネットワーク I/O など CPU を使わない瞬間もあります。例えば、実行時間が 5 秒のサーチであれば、CPU を 2 秒、その他の処理に 3 秒というような形に整理することができます。
スループット
例えば 16 CPU の Indexer で 4 CPU がデータ取り込みに使われていると仮定した場合、どれだけのサーチを実行することができるのでしょうか。ディスクやネットワーク I/O など、CPU を使わない処理時間についてはボトルネックがなく、完全に並列できる前提で考えてみましょう。
サーチのスループットを考える際、必ず必要になる情報が単位時間です。よく、「同時に実行できるサーチは何個ですか」という質問を受けることがありますが、ある一瞬だけを切り取ると、16 CPU のうち 4 CPU がデータ取り込みに使われている Indexer では 12 個のサーチしか実行できないという回答しかできません。したがって、必ず単位時間を条件に指定して、例えば「1 時間で何個のサーチが実行できるか」という形でスループットを考える必要があるわけです。
さらに必要な情報が 1 つのサーチの平均 CPU 利用時間です。仮に 1 サーチ平均で CPU を 2 秒利用するとした場合、12 CPU がサーチに使える状況であれば、1 時間に実行できる最大サーチ数は、以下の計算のように 21,600 ということになりそうです。
3600 x 12 / 2 = 21,600
待ち行列
しかし、本当に 21,600 のサーチが実行できるのでしょうか。CPU 利用時間 2 秒という数値はあくまで平均であり、サーチによってはそれ以上かかる場合もあるはずです。待ち行列の基本的な考え方を当てはめて、もう少し現実的に考えてみましょう。
- 到着率
1 秒間に到着するサーチの数:λ(ラムダ) = 1 時間当たりのサーチ数 / 3600 - サービス率
1 CPU で 1 秒間に処理できるサーチ数:μ(ミュー) = 1 / サーチの平均 CPU 利用時間 - 利用率
Indexer 全体のサーチ許容量に対する利用率:ρ(ロー) = λ / (μ x CPU 数)
最後の利用率が極めて重要な数値になります。一般的には、この値が 0.7 を超えると目に見えて待ち行列が発生するようになります。ラーメン屋に人が並んでいるのと同じような感じで、サーチは CPU が空くのを待つようになります。利用率が 1 以上の場合には行列が無限に長くなり、Indexer としては完全に破綻をきたす状態になります。
1 サーチ平均 CPU 利用時間 2 秒、利用できる CPU 数 12 という条件で、1 時間に 21,600 サーチが投入される場合の計算は以下のようになります。
λ = 21600 / 3600 = 6
μ = 1 / 2 = 0.5
ρ = 6 / (0.5 x 12) = 1
つまり、21,600 という数値は Indexer が破綻を始めるサーチ数上限ということになります。利用率が 0.7 を超えれば CPU 待ちが発生するようになるので、現実には 21,600 サーチを 1 時間で実行することはできないと考えるべきです。現実的なスループットは利用率が 0.7 にとどまるサーチ数とするべきなので、以下の計算で求められる 15,120 サーチとなります。
ρ = 0.7 = λ / (0.5 x 12)
λ = 0.7 x (0.5 x 12) = 4.2
3600 x 4.2 = 15120
ロードアベレージ
実際に皆さんが利用している Indexer で CPU 待ち行列が発生しているのか、発生している場合、待ち時間はどのくらいなのかを知りたい場合はどうすればいいでしょうか。CPU 利用率は見れば CPU がどのくらい使われているかが分かりますので、100% に近ければ待ち行列が発生していると想像することはできます。しかし、CPU 使用率は 100% で頭打ちになるため、実際にどのくらいの待ち行列になっているのかまでは分かりません。
Splunk では以下のサーチを実行することで、Indexer 上で 1 CPU 当たりに実行されているサーチと CPU を待機しているサーチの数、ロードアベレージを知ることができます。
index=_introspection sourcetype=splunk_resource_usage component=Hostwide host=<<インデクサーホスト名>>
| bin _time span=1h
| rename data.normalized_load_avg_1min as La
| eval cpu_pct = 'data.cpu_system_pct' + 'data.cpu_user_pct'
| stats avg(cpu_pct) avg(La) p99(cpu_pct) p99(La) by _time
| foreach *
[ eval <<FIELD>> = round('<<FIELD>>', 2) ]
avg(La) の値が 1 未満、p99(La) の値が 2 未満であれば、健全と考えていいでしょう。待ち行列で紹介した利用率が 0.7 を超えてくる当たりでロードアベレージの値が 1 を超えてくると思います。
ロードアベレージと CPU 使用率、CPU 数を使ってどのくらいの待ち時間が発生しているかを計算する SPL を作ってみました。数値は様々な前提に基づく計算結果なので、正確な数値にはなりませんが、皆さんのサーチがベストな状態で実行されているのかどうかを判断する目安として活用してみてください。
(index=_audit (host=<<サーチヘッドホスト名>> OR host=si*.splunkcloud.com) sourcetype=audittrail action=search total_run_time=*) OR (index=_introspection sourcetype=splunk_resource_usage component=Hostwide host=<<インデクサーホスト名>>)
| bin _time span=1h
| rename data.normalized_load_avg_1min as La
| eval cpu_pct = 'data.cpu_system_pct' + 'data.cpu_user_pct'
| eval host = if(match(host, "^idx"), host, null())
| eval CPU = if(match(host, "^idx"), 'data.cpu_count', 0)
| stats dc(host) as idx_count count(total_run_time) as search_count sum(total_run_time) avg(total_run_time) p99(total_run_time) avg(cpu_pct) p99(cpu_pct) avg(La) p99(La) max(CPU) as CPU by _time
| eval ingest_CPU = min(4, CPU * .75)
| eval search_CPU = CPU - (ingest_CPU + 0.5)
| eval concurrency = 'sum(total_run_time)' / 3600 / search_CPU
| eval cpu_run_wait_time_pct = 'avg(La)' / concurrency * 100
| eval cpu_run_wait_time = 'avg(total_run_time)' * cpu_run_wait_time_pct / 100
| eval cpu_run_wait_time99 = 'p99(total_run_time)' * 'cpu_run_wait_time_pct99' / 100
| fields _time idx_count search_count sum(total_run_time) avg(total_run_time) p99(total_run_time) cpu_run_wait_time_pct cpu_run_wait_time avg(cpu_pct) p99(cpu_pct) avg(La) p99(La) concurrency CPU ingest_CPU search_CPU
| appendpipe
[ eval cpu_run_wait_time_pct = cpu_run_wait_time_pct * search_count
| stats sum(search_count) avg(idx_count) as idx_count avg(search_count) as search_count sum(sum(total_run_time)) avg(p99(total_run_time)) as p99(total_run_time) sum(cpu_run_wait_time_pct) avg(avg(cpu_pct)) as avg(cpu_pct) avg(p99(cpu_pct)) as p99(cpu_pct) avg(avg(La)) as avg(La) avg(p99(La)) as p99(La)
| eval cpu_run_wait_time_pct = 'sum(cpu_run_wait_time_pct)' / 'sum(search_count)'
| eval avg(total_run_time) = 'sum(sum(total_run_time))' / 'sum(search_count)'
| eval _time = "Average"
| fields - sum(search_count) sum(cpu_run_wait_time_pct) sum(sum(total_run_time)) ]
| appendpipe
[ stats p50(idx_count) as idx_count p50(search_count) as search_count p50(avg(total_run_time)) as avg(total_run_time) p50(p99(total_run_time)) as p99(total_run_time) p50(cpu_run_wait_time_pct) as cpu_run_wait_time_pct p50(cpu_run_wait_time) as cpu_run_wait_time p50(avg(cpu_pct)) as avg(cpu_pct) p50(p99(cpu_pct)) as p99(cpu_pct) p50(avg(La)) as avg(La) p50(p99(La)) as p99(La)
| eval _time = "P50" ]
| appendpipe
[ stats p99(idx_count) as idx_count p99(search_count) as search_count p99(avg(total_run_time)) as avg(total_run_time) p99(p99(total_run_time)) as p99(total_run_time) p99(cpu_run_wait_time_pct) as cpu_run_wait_time_pct p99(cpu_run_wait_time) as cpu_run_wait_time p99(avg(cpu_pct)) as avg(cpu_pct) p99(p99(cpu_pct)) as p99(cpu_pct) p99(avg(La)) as avg(La) p99(p99(La)) as p99(La)
| eval _time = "P99" ]
| eval cpu_run_wait_time = 'avg(total_run_time)' * cpu_run_wait_time_pct / 100
| filldown search_CPU
| eval lambda = search_count / 3600
| eval Ls = search_CPU * 'avg(cpu_pct)' / 100
| eval Ls99 = search_CPU * 'p99(cpu_pct)' / 100
| eval Lq99 = 'p99(La)' * search_CPU
| eval avg(cpu_run_time) = Ls / lambda
| eval avg(cpu_wait_time) = cpu_run_wait_time - 'avg(cpu_run_time)'
| eval p99(cpu_wait_time) = max((Lq99 - Ls99) / lambda, 'avg(cpu_wait_time)')
| fields - sum(total_run_time) concurrency CPU ingest_CPU cpu_run_wait_time_pct cpu_run_wait_time
| foreach *
[ eval <<FIELD>> = round('<<FIELD>>', 2) ]
| eval mu = 1 / 'avg(cpu_run_time)'
| eval rho = lambda / (search_CPU * mu)
| eval mu = round(mu, 4), rho = round(rho, 4)
| eval idx_count = round(idx_count)
| fields _time idx_count search_count avg(total_run_time) p99(total_run_time) avg(cpu_pct) p99(cpu_pct) avg(La) p99(La) search_CPU lambda mu rho avg(cpu_run_time) avg(cpu_wait_time) p99(cpu_wait_time)
注意して実装してみましたが、誤りがあるかもしれません。その場合はお知らせいただけると嬉しいです。