行フィルタは読む量を減らさない
一言でいうと
Lokiのクエリのコストは、読み取ったバイト数で決まります。そして、読む量を減らせるのは、ストリームセレクターと時間区間の2つだけです。行フィルターとパーサーは、すでに読んだ行をふるいにかけるだけです。
なぜ必要なのか
明け方に決済エラーを調査していた人が、Grafanaで{cluster="prod"} |= "payment" |= "timeout"を1日の区間で投げました。クエリは4分間動いたあと、タイムアウトで切られました。隣の人が{cluster="prod", app="pay"}に変え、区間を30分に絞ると、2秒で答えが出ました。2つのクエリの結果は同じでした。
違いは、読んだ量です。最初のクエリは、そのクラスターのすべてのストリームを1日分読んでからふるいにかけ、2つ目は、1つのストリームを30分分だけ読みました。行フィルター2つは、読む量を1バイトも減らしませんでした。
どう動くのか
Lokiは本文をインデックス化しません。インデックスにあるのは、ラベルの組み合わせ(ストリーム)と、そのストリームのチャンクがどの時間帯にあるかだけです。そのため、クエリが実行される順序は、常に同じです。
- セレクターがインデックスを見て、どのストリームのどのチャンクを開くかを選びます。
- 時間区間が、そのチャンクのうち重なるものだけを残します。
- 残ったチャンクをすべて読み、行フィルターとパーサーとラベルフィルターを順に適用します。
1つ目と2つ目だけが、読む量を決めます。3つ目は、すでに読んだものを捨てる作業です。そのため、レスポンスに載ってくる統計のうち、totalLinesProcessedとtotalBytesProcessedはセレクターと区間にだけ反応し、totalPostFilterLinesと返された行数だけがフィルターに反応します。この2つのペアを分けて読むことが、Lokiのクエリをチューニングする方法のほぼすべてです。
だからといって、行フィルターが無駄というわけではありません。行フィルターはパーサーよりずっと安いです。パーサーは行ごとに構文を解釈してラベルを作る必要があり、ラベルフィルターはそのラベルを比較します。そのため、パーサーを付けるときは、前に行フィルターを置いて、パーサーが見る行数を減らすのが、やはり得です。ただし、その得は読むバイトではなくCPUで生まれます。2つを混ぜて話すと、「行フィルターを前に置いたのに、なぜ速くならないのか」で行き詰まります。
limitは当てにできるコストのつまみではありません。単純なログクエリでは、Lokiが必要な分を集めたあと早めに止まれるため、読む量が減ることもあります。ただし、どれだけ減るかは、クエリが何個に分割されて並列で動くかに依存しており、同じクエリを同じ区間に2回投げても、読んだ行数が異なって出ます(このラボ環境で実際にそうなりました)。そのため、「limitを減らしてコストを節約しよう」という計画は立てられず、メトリクスクエリにはlimitがそもそも適用されません。
ラベル設計が結局クエリ性能になる理由が、ここにあります。appラベルがなければ、そもそも絞る方法がなく、逆にuser_idのようなものをラベルに入れると、ストリームが爆発して、インデックス参照そのものが高価になります。絞れる分だけをラベルにして、残りは本文に。このバランスが、Loki運用の中心です。
現場での姿
コストの事故は、たいていダッシュボードで起きます。人が手で投げるクエリは1日に数回ですが、ダッシュボードのパネルは30秒ごとに自動で動きます。セレクターが緩いパネル1つが、1か月で数十テラバイトを読みます。そのため、ダッシュボードを作るときは、パネルごとに統計を一度ずつ取ってみて、読む量が大きいパネルは、セレクターを絞るか、デフォルトの区間を短くしておきます。
もう1つ。人は調査のとき、区間を広く取る癖があります。「いつかわからないから、とりあえず1日」です。しかし、インシデントの時刻は、たいていメトリクスやアラートですでにわかっています。まずメトリクスで時刻を固定し、ログはその前後15分だけを見る順序に変えると、同じ調査が10倍速くなります。
次のラボですること
4つのストリームの2400行をPodのLokiに入れ、まれに混ざっている目印の1行を探すクエリを、4つの方法で投げてみます。毎回、レスポンスのstats.summaryを読んで、読んだ行数とバイト数を記録し、セレクターを絞ったときと、区間を絞ったときにだけ、その数字が減ることを表にしたあと、最後に、決められた予算の中で同じ答えを出すクエリを自分で書いて提出します。