遅いという報告には、直す場所がない

一言でいうと

注文が通った場所ごとに時刻が刻まれていなければ、どの区間が遅いのかを言えません。そして、区間の両端が別のマシンなら、その差には、2つのマシンの時計の誤差がそのまま混ざり込みます。

なぜ必要なのか

「注文が遅いです」という報告を受けると、最初はすることがありません。何が遅いのか、わからないからです。ゲートウェイが遅いのか、リスクチェックに時間がかかっているのか、回線が詰まっているのか、取引所が受け付けるのが遅いのか。候補が4つあり、直すチームは4つとも違います。この状態で会議を開くと、各チームが自分の区間は問題ないと言い、誰も間違ったことを言わないまま、何も直りません。

そのため、最初にすることは、経路に物差しを当てることです。注文1つが自分たちの中で通る場所を決め、その場所ごとに時刻を残します。受信、リスクチェック完了、セッションエンコード完了、回線送信、取引所の受付、ack受信。6つの場所を決めれば5つの区間ができ、そのときから、「遅い」は「この区間がこれだけ遅い」に変わります。変わった瞬間、直すチームが決まります。

どう動くのか

区間遅延は、後ろの時刻から前の時刻を引いた値です。簡単に見えますが、ここに落とし穴が1つあります。2つの時刻を同じマシンが刻んだかが、値の意味を変えます。

同じマシンの中の2つの時刻なら、その差は、そのマシンの時計がどれだけ正確かとほとんど無関係です。時計が3ミリ秒進んでいても、2つの時刻の両方が3ミリ秒進んでいるので、引けば消えます。そのため、同じマシンの中の区間は信頼でき、ここでは単調時計を使うほうがよいです。壁時計は、時刻同期の補正が入ると後ろに戻ることがありますが、単調時計は後ろに戻りません。

逆に、両端が別のマシンの区間には、2つのマシンの時計の誤差がそのまま入ります。こちらのゲートウェイが回線に出した時刻と、取引所が受け付けたと刻んだ時刻の差は、本当の回線時間に、2つの時計の差を足した値です。取引所の時計がこちらより遅れていると、この値は負の数で出ます。光より速く進んだという意味ではなく、物差しが間違っているのです。

ところが、往復は相殺されます。回線送信時刻とack受信時刻は、どちらもこちらのマシンが刻みます。その間に注文が取引所を往復しましたが、2つの時刻が同じ時計から出たので、取引所の時計がどれだけ間違っていても、差には入ってきません。片道は汚染され、往復はきれいだというこの性質が、RFC 5905の時刻同期がオフセットを測る方式の土台でもあります。そのため、片道の区間を見るには、オフセットの報告を受け取って補正する必要があり、補正したあとも負の数が残る区間が、本当の欠陥です。ここでよくある間違いは、逆の側です。ある区間がまるごと負の数で出ると、「全部時計のせい」とひとまとめにしてしまいますが、その中に混ざっていた本当の1件が、そうして消えます。

集めたあとは、平均を見ません。遅延の分布は片側に長く伸びているので、平均は、少数の遅い件に引きずられます。代わりに、パーセンタイルを見ます。ただし、パーセンタイルには定義が複数あるという事実が重要です。並べ替えて、その位置の値をそのまま使う方式と、2つの値の間を補間する方式は、同じデータから違う数字を出します。statisticsモジュールの説明にも、方式が複数書かれています。こちらのダッシュボードと相手の契約書が違う定義を使っていると、同じ回線について、一方は違反だと言い、他方は違反ではないと言います。そのため、定義をデータの横に書いておき、そのとおりに実装します。

そして、区間別のパーセンタイルは、全体のテールを説明できません。区間ごとにp99を出すと、普通は回線の区間が最も大きくなります。ところが、全体の遅延が最も悪い上位1パーセントの注文を取り出して、その注文たちの最も大きな区間を数えてみると、別の区間が出ることもあります。区間別のp99は、各区間で互いに異なる注文を見ており、全体のテールは、1つの注文の中で何が大きかったかを見ています。2つの質問が違うので、答えも違います。直す場所を決めるのは、後者です。

最後が、レイテンシバジェットです。区間ごとに上限を決めておき、超過件数を数えます。バジェットの値は、好みではなく決定です。緩く取れば異常なものだけが引っかかり、締めれば正常な変動まで引っかかって、警報が1日に数千件になります。その瞬間、誰もその警報を見なくなるので、バジェットは2セット作って、超過件数を実際に数えてみて決める必要があります。

現場での姿

あるとき、回線の区間が負の数で出るという理由で、その区間の測定がまるごと捨てられたことがあります。数か月後、取引所と応答時間について話し合うことになったとき、こちらには、その区間の数字がありませんでした。オフセットの報告を受け取って引くだけで済むことでしたが、負の数を見た人が「測定が壊れている」と判断して、ダッシュボードから消したのが、すべてでした。

また別のときは、回線の区間のp99が最も大きいという理由で、回線の増強が決まったことがあります。増強のあとも、遅い注文の報告は減りませんでした。最も遅い注文たちを開き直してみると、その注文たちで大きな区間は、回線ではなく、リスクチェックとエンコードの間の待機で、それは特定の時間帯にだけ現れました。区間別のp99と全体のテールを同じ質問とみなした代償でした。

次のラボですること

注文1500件の区間タイムスタンプとホスト別の時計オフセットの報告、レイテンシバジェット2セット、パーセンタイルの定義を、データとして作ります。区間遅延を計算して負の数が出る箇所を探し、オフセットで補正して、時計の誤差と本当の欠陥を分けます。そのあと、区間別のパーセンタイルと、全体のテールを作る区間を別々に数えて、2つが違うことを確認し、バジェット2セットの超過件数を比べます。最後に、どの区間が何分から悪化したかと、データで排除した仮説を、あわせて書きます。