push は 204 なのにクエリは空で返る
一言でいうと
Lokiに入れた行は、まずインジェスターのメモリにたまり、あとでチャンクとしてストレージに下ろされます。クエリは「最近の数時間」だけをインジェスターに尋ねるので、それより古いタイムスタンプで入れた行は、受け付けられても見えません。
なぜ必要なのか
障害復旧中のチームがありました。コレクターが2時間止まっており、その間にたまったファイルを復旧してLokiに流し込みました。pushはすべて204を返しました。ところが、Grafanaでその時間帯を開いても、何もありませんでした。
人々は「pushが嘘をついている」と考えました。実際には、行はインジェスターの中にきちんと入っていて、クエリがその区間をインジェスターに尋ねていなかっただけです。強制的にフラッシュを実行してチャンクをストレージに下ろすと、同じクエリですべて出てきました。
どう動くのか
書き込み経路は次のとおりです。
- pushが到着すると、インジェスターがストリームごとに開いているチャンクに行を追記します。同じ内容をWALにも書いて、インジェスターが落ちても復元できるようにします。
- チャンクは、3つの条件のうち1つに当たると閉じます。目標サイズに到達(
chunk_target_size)、一定時間新しい行がない(chunk_idle_period)、開いてから長すぎる(max_chunk_age)です。 - 閉じたチャンクはオブジェクトストレージに上がり、インデックスには、そのストリームと時間範囲が記録されます。
読み取り経路は2系統です。クエリはストレージに尋ね、最近の区間なら、まだストレージに下りていない行のためにインジェスターにも尋ねます。ここで「最近」を決めるのがquerier.query_ingesters_withinで、デフォルト値は3時間です。区間の終わりがそれより過去なら、クエリはインジェスターを飛ばします。
そのため、過去のタイムスタンプで入れた行は、この2つの経路の間の隙間に落ちます。ストレージにはまだなく、インジェスターにはあるのに、誰も尋ねません。時間がたってチャンクが自然に閉じて上がれば、見え始めます。そのため、「しばらくたってから自然に現れた」という話が出てきます。
この設計は間違いではありません。インジェスターに尋ねるのは高価で、古い区間まで毎回尋ねると、すべてのクエリが遅くなります。ただし、あとから流し込む復旧作業では、この前提が崩れます。
運用で覚えておくことは3つです。1つ目、復旧で過去のデータを流し込んだなら、フラッシュを待つか、強制的に実行します。2つ目、古すぎるデータは、そもそも拒否されることもあります。reject_old_samplesとreject_old_samples_max_ageがそのつまみです(このラボの設定は、わざとオフにしてあります)。3つ目、このPodのLokiは、すべての構成要素が1つのプロセスに入った単一バイナリモードです。運用でインジェスター・クエリアー・コンパクターが別々に起動する場合も、同じ原理がそのまま当てはまりますが、フラッシュを呼ぶ場所と、見るべきメトリクスが変わります。
現場での姿
最もよく見る症状は、「ダッシュボードの直近15分は問題ないのに、昨日の区間が空になっている」です。最近の区間はインジェスターが答え、過去の区間はストレージが答えるので、ストレージに上がる道がふさがっていると、まさにこの形になります。オブジェクトストレージの認証情報が期限切れになった事故では、必ずこう現れます。
2つ目は、インジェスター再起動直後の空白の区間です。WALの再生が終わる前は、その区間が空に見え、再生が終われば埋まります。そのため、インジェスターを入れ替えるデプロイ中に「ログが消えた」という報告が来たら、まず数分待ってみるのが正しい対応です。
3つ目は、チャンクサイズのチューニングです。目標サイズを小さく取りすぎると、オブジェクトが無数に増えて、インデックスとクエリが遅くなり、大きく取りすぎると、インジェスターのメモリが大きくなり、再起動時に失うものが増えます。
次のラボですること
PodのLokiに、最近のデータと5時間前のデータをそれぞれ入れ、後者が、受け付けられるのにクエリでは空であることを自分で見ます。その境界を決める設定を、サーバーの/configで見つけて確認し、強制フラッシュの前後で、ストレージのチャンクファイル数とクエリ結果がどう変わるかを数字で記録します。最後に、6時間前の行を1つ自分で入れて、見えるようにするところまで行います。