同じ答えを返す二つのクエリが、片方は四分、片方は二秒だった

目標

Lokiのレスポンスに載ってくるstats.summaryを読んで、クエリが実際に何行・何バイトを読んだかを測り、何がその数字を減らし、何が減らさないかを、自分で確認します。

なぜ重要なのか

Lokiのインデックスには、ラベルの組み合わせとチャンクの時間範囲だけが入っています。本文はインデックス化されません。そのため、クエリは常に同じ順序で動きます。セレクターが開くチャンクを選び、時間区間がそのうち重なるものだけを残し、残ったものをすべて読んでフィルターを適用します。前の2段階だけが読む量を決め、あとはすでに読んだものを捨てる作業です。この順序を知らないと、行フィルターを前に置いたり、limitを減らしたりしながら、クエリが速くなるのを待つことになります。コストがバイトで課金されるストレージでは、この違いがそのまま請求書です。

ステップ

/root/lk-filtersでLokiを起動し、date +%sを/root/lk-filters/anchor.txtに書いたあと、python3 /opt/lab/d5/gen.py filters "$(cat anchor.txt)"でデータを入れてください。そして、{app=~"edge|cart|ship|batch"}を基準時刻から過去1時間の区間でクエリして、レスポンスのstats.summaryから、読んだ行数とバイト数を、/root/lk-filters/01-base.txtにprocessed=<정수>とbytes=<정수>の2行で書いてください(プレースホルダーは整数です)。
同じ1時間の区間で、4つのストリーム全体を対象に、本文にSETTLE-LATEが入っている行を探すクエリを/root/lk-filters/02-marker.logqlに書き、結果の行数と読んだ行数を/root/lk-filters/02-marker.txtにlines=<정수>とprocessed=<정수>の2行で書いてください(プレースホルダーは整数です)。
同じ答え(同じ行)を出しながら、ストリームセレクターだけを絞ったクエリを/root/lk-filters/03-stream.logqlに書き、結果の行数と読んだ行数を/root/lk-filters/03-stream.txtにlines=<정수>・processed=<정수>で書いてください。そして/root/lk-filters/03-ratio.txtにratio=<소수 둘째 자리>の1行で、ステップ2に対する、読んだ行数の比率を書きます(プレースホルダーは整数と、小数第2位までの値です)。
ステップ3と同じクエリを、区間だけを30分(基準時刻から過去1800秒)に変えて投げてください。結果の行数と読んだ行数を/root/lk-filters/04-window.txtにlines=<정수>・processed=<정수>で書き、/root/lk-filters/04-note.txtにtradeoff=で始まる1文(空白を除いて40文字以上)を書いて、区間を絞ると何を得て何を失うかを、自分の言葉で書いてください。
4つのストリーム全体・1時間の区間で、2つのクエリを投げて、読んだ行数を比べてください。1つはフィルターがまったくない{app=~"edge|cart|ship|batch"}、もう1つは、それに行フィルターを2つ加えたクエリです。結果を/root/lk-filters/05-linefilter.txtに4行で書きます。plain_processed=、plain_lines=、filtered_processed=、filtered_lines=です。
4つのストリーム全体・1時間の区間に、| logfmt | status="500"を付けたクエリを投げて、3つの数字を/root/lk-filters/06-parser.txtに書いてください。processed=<읽은 줄 수>、post_filter=<필터를 통과해 남은 줄 수>、lines=<결과 줄 수>です(プレースホルダーは順に、読んだ行数、フィルターを通過して残った行数、結果の行数です)。3つの数字をステップ1の基準線と比べて、何が同じで何が変わったかを見てください。
ここまでに測ったものを/root/lk-filters/cost.tsvにまとめてください。ヘッダーなしで4行で、各行はタブで区切った3つの欄<방법><탭><읽은줄수><탭><결과줄수>(プレースホルダーは順に、方法、タブ、読んだ行数、結果の行数です)です。方法名は順にall(ステップ2)、stream(ステップ3)、window(ステップ4)、parser(ステップ6)です。
/root/lk-filters/08-budget.logqlにクエリを1つ書いてください。条件は3つです。(1)基準時刻から過去1時間の区間で投げたとき、ステップ2とまったく同じ行を返してください、(2)読んだ行数を、ステップ1の基準線の3分の1以下にしてください、(3)limitに頼らないでください。そして/root/lk-filters/08-budget.txtにprocessed=<정수>の1行で、そのクエリが読んだ行数を書いてください(プレースホルダーは整数です)。

参考

作業ディレクトリは/root/lk-filtersです。Lokiはステップ1で自分で起動します。
データ生成器は/opt/lab/d5/gen.pyで、filtersデータを書き込みます。採点ツールはこのファイルを読みません。
統計はcurl ... | jq '.data.stats.summary'で見ます。このラボが見る欄は、totalLinesProcessed・totalBytesProcessed・totalPostFilterLinesです。execTimeは、同じクエリでも実行するたびに変わるので、判断の根拠にしないでください。
模範解答が作るcost.shは便宜上のヘルパーです。直接curlで投げてもかまいません。
よくある間違い: since=1hで測ってしまいます。時間が経つと答えが変わり、再採点で落ちます。
よくある間違い: 安くなったクエリが答えまで変えてしまったのに、気づかずに先へ進んでしまいます。コストを減らすたびに、結果の行数も一緒に確認してください。
LogQL概要・ログクエリ・ラベル・構造・HTTP API

4つのストリームを入れて、基準線を測る

/root/lk-filtersでLokiを起動し、date +%sを/root/lk-filters/anchor.txtに書いたあと、python3 /opt/lab/d5/gen.py filters "$(cat anchor.txt)"でデータを入れてください。そして、{app=~"edge|cart|ship|batch"}を基準時刻から過去1時間の区間でクエリして、レスポンスのstats.summaryから、読んだ行数とバイト数を、/root/lk-filters/01-base.txtにprocessed=<정수>とbytes=<정수>の2行で書いてください(プレースホルダーは整数です)。

統計は、query_rangeのレスポンスのdata.stats.summaryに入っています。jq '.data.stats.summary'で、一度まるごと見てください。totalLinesProcessedとtotalBytesProcessedの2つの欄です。この数字が、このラボの間ずっと比べる基準線です。

5行を見つけるために、何行読んだか

同じ1時間の区間で、4つのストリーム全体を対象に、本文にSETTLE-LATEが入っている行を探すクエリを/root/lk-filters/02-marker.logqlに書き、結果の行数と読んだ行数を/root/lk-filters/02-marker.txtにlines=<정수>とprocessed=<정수>の2行で書いてください(プレースホルダーは整数です)。

行フィルター1つで済みます。重要なのは答えではなく、答えを得るために読んだ量です。2つの数字を並べて見てください。読んだ行数が、ステップ1の基準線と同じかも確認してください。

セレクターを絞ると、読む量が減る

同じ答え(同じ行)を出しながら、ストリームセレクターだけを絞ったクエリを/root/lk-filters/03-stream.logqlに書き、結果の行数と読んだ行数を/root/lk-filters/03-stream.txtにlines=<정수>・processed=<정수>で書いてください。そして/root/lk-filters/03-ratio.txtにratio=<소수 둘째 자리>の1行で、ステップ2に対する、読んだ行数の比率を書きます(プレースホルダーは整数と、小数第2位までの値です)。

目印がどのサービスから出ているかは、ステップ2の結果のstreamラベルを見ればわかります。セレクターをその1つに絞ってください。結果の行数はそのままである必要があります。答えを変えずに、コストだけを減らすことが、このステップの要点です。比率は、ステップ3の読んだ行数をステップ2の値で割ります。

区間を絞ると、読む量が減り、答えも減る

ステップ3と同じクエリを、区間だけを30分(基準時刻から過去1800秒)に変えて投げてください。結果の行数と読んだ行数を/root/lk-filters/04-window.txtにlines=<정수>・processed=<정수>で書き、/root/lk-filters/04-note.txtにtradeoff=で始まる1文(空白を除いて40文字以上)を書いて、区間を絞ると何を得て何を失うかを、自分の言葉で書いてください。

クエリ文はそのままにして、startだけを変えます。読んだ行数が半分ほどに減りますが、結果の行数も一緒に減ります。区間の外にある答えは、まったく見えません。インシデントの時刻を知らないまま、区間から先に絞ると、何が危険かを考えてみてください。

行フィルターを足しても、読む量はそのまま

4つのストリーム全体・1時間の区間で、2つのクエリを投げて、読んだ行数を比べてください。1つはフィルターがまったくない{app=~"edge|cart|ship|batch"}、もう1つは、それに行フィルターを2つ加えたクエリです。結果を/root/lk-filters/05-linefilter.txtに4行で書きます。plain_processed=、plain_lines=、filtered_processed=、filtered_lines=です。

行フィルターは何でもかまいません(例: |= "level=error"と!= "route=/a")。見るべきなのは、4つの数字の関係です。どのペアが同じで、どのペアが違うか。同じほうが「読んだ量」、違うほうが「残った量」です。

パーサーを付けても、読む量はそのまま

4つのストリーム全体・1時間の区間に、| logfmt | status="500"を付けたクエリを投げて、3つの数字を/root/lk-filters/06-parser.txtに書いてください。processed=<읽은 줄 수>、post_filter=<필터를 통과해 남은 줄 수>、lines=<결과 줄 수>です(プレースホルダーは順に、読んだ行数、フィルターを通過して残った行数、結果の行数です)。3つの数字をステップ1の基準線と比べて、何が同じで何が変わったかを見てください。

totalPostFilterLinesが、統計の3つ目の欄です。cost.shはこの欄を出さないので、curl ... | jq '.data.stats.summary'で直接見るか、ヘルパーを直して使ってください。パーサーは、行フィルターより高価な作業をしますが、読む量という基準では、2つは同じ位置にあります。

応用①: 4つの方法のコスト表

ここまでに測ったものを/root/lk-filters/cost.tsvにまとめてください。ヘッダーなしで4行で、各行はタブで区切った3つの欄<방법><탭><읽은줄수><탭><결과줄수>(プレースホルダーは順に、方法、タブ、読んだ行数、結果の行数です)です。方法名は順にall(ステップ2)、stream(ステップ3)、window(ステップ4)、parser(ステップ6)です。

前のステップで作ったファイルから値を取り出して集めれば済みます。表を作ると、一目でわかります。読んだ行数が実際に減った行はいくつあるか。

応用②: 予算の中で同じ答えを出すクエリ

/root/lk-filters/08-budget.logqlにクエリを1つ書いてください。条件は3つです。(1)基準時刻から過去1時間の区間で投げたとき、ステップ2とまったく同じ行を返してください、(2)読んだ行数を、ステップ1の基準線の3分の1以下にしてください、(3)limitに頼らないでください。そして/root/lk-filters/08-budget.txtにprocessed=<정수>の1行で、そのクエリが読んだ行数を書いてください(プレースホルダーは整数です)。

読む量を減らすつまみは、2つだけです。このステップは区間を変えられないので、残りの1つで解く必要があります。ステップ2の結果のstreamラベルが答えを教えてくれます。クエリを変えたあとで、結果の行数がそのままかを、必ず測り直してください。安くなったのに答えが変わったなら、チューニングではなく事故です。