黙って切られる答えが一番危ない

一言でいうと

limitは答えを静かに切り、サーバーの上限はクエリを400で拒否します。インシデント調査を台無しにするのは、いつも静かなほうです。

なぜ必要なのか

インシデントの原因を探していた人が、{app="gateway"} |= "timeout"を2時間の区間で投げました。結果は1000行で、最も早い行の時刻をインシデントの開始として報告しました。あとで見ると、実際の開始は、それより40分前でした。

limitのデフォルト値が1000で、方向がbackwardでした。つまり、直近の1000行だけが返ってきて、それより前の行は画面に現れませんでした。レスポンスのどこにも「切り捨てられた」という表示はありませんでした。返ってきた行数がちょうどlimitと同じだということが、唯一の手がかりでした。

どう動くのか

ログクエリの結果数を決めるものは、3つあります。

つまみ	性質	超えると
リクエストのlimit	クライアントが選びます	静かに切られます
limits_config.max_entries_limit_per_query	サーバーが決めた上限です	400で拒否されます
limits_config.max_query_length	区間の長さの上限です	400で拒否されます

directionが、何が切り捨てられるかを決めます。backward(デフォルト)は最近のものから埋めるので、古い行が切られ、forwardはその逆です。インシデントの開始を探すときに、デフォルトのまま使うと、まさに見つけたいものが切り捨てられます。

クエリはさらに、split_queries_by_intervalに従って、時間の断片に分割され、並列で動きます。レスポンス統計のsplitsが、その断片の数です。断片が多いほど早く終わりますが、スケジューラーとクエリアーに負荷が集中します。逆に、断片が0なら、1つの断片で動いたということです。

そのため、広い区間をスキャンする必要があるときの正しい方法は、limitを大きくすることではありません。区間を切って何度も尋ねて、合算することです。各断片の結果数がlimitより小さければ、その断片は完全であることが保証され、合計も信頼できます。自動化スクリプトは、ほとんど常にこの形であるべきです。

上限を引き上げることが答えになる場合は、まれです。max_entries_limit_per_queryを大きくすると、クエリアーのメモリが大きくなり、1人のクエリがクラスター全体を揺るがすことがあります。上限はインシデントを防ぐ安全装置であって、邪魔者ではありません。

現場での姿

1つ目、「返ってきた行数 == limit」なら、無条件に疑います。自動化なら、この条件を明示的に検査して、警告を出す必要があります。人が使うダッシュボードなら、パネルのタイトルにlimitを書いておくだけでも、誤解が大きく減ります。

2つ目、調査の開始時刻を探すときは、direction=forwardを使います。この1語が、報告書のタイムラインを変えます。

3つ目、400レスポンスの本文は、たいてい親切です。どの上限をどれだけ超えたかを、数字まで書いてくれます。自動化でその本文を捨ててステータスコードだけをログに残すと、あとで原因を探すために、同じクエリを手でもう一度投げることになります。

次のラボですること

2時間にわたるデータを入れ、limitを小さくしたときに静かに切られることを、数字で確認します。サーバーの上限をわざと超えて、400とその本文を自分で受け取り、区間の長さの上限も同じ方法で確認します。splitsが区間によってどう変わるかを測り、最後に、上限の範囲内で区間を分割して、2時間分を漏れなく数えるスクリプトを作ります。