プロキシのせいにしたバグで、84,000件の出品を危うく失いかけた週

9月14日

私たちは何週間もこの日を待ち続けていた。7月、レジデンシャルプロキシのプロバイダが請求トラブルで音信不通になり、以来2か月のあいだ、1,375ソースのうち増え続ける一部が劣化した状態でクロールされるか、あるいはまったくクロールされないという状況が続いていた。フェッチがタイムアウトし、IPがセッション途中でブロックされる——はっきりした障害としては現れず、誰も気づかないうちに数字がじわじわと縮んでいき、気づいたときには気まずい状態になっている、そういう類の緩慢な出血だった。そこでようやく契約を更新した。新しいプール、20,000本のローテーション式レジデンシャルセッション回線、本番環境に近づける前にすべての出口をプローブ済み。プローブは100%通過。UAE、ドイツ、日本——すべて生きていて、すべてクリーンだった。

そこで、誰かが実際にダッシュボードを見張り、cronを信用し切らない形の「監視付きクロール」を実行した。私が予想していたのは、惨事とは正反対の結果だった。

ところが実際に起きたのは、たった一回のクロールでデータベースが84,401行を失い、102ソースが直前のスナップショットから25%以上も減少するという事態だった。たった今直したばかりの、2か月分のプロキシ枯渇よりもひどい結果だ。

間違った仮説、手短に

私の最初の直感は——これは正直に認めるが——新しいプールはプローブが示していたより実は悪かったのではないか、というものだった。セッションIPがクロール途中でレート制限を受けていて、ワンショットのプローブでは検知できなかったのかもしれない、と。もっともらしい仮説ではある。だが間違っていた。そしてその仮説を半日でも信じ続けたことで、私たちは本来なら余裕のない時間を失った。この手の仮説を検証している間は、クロール用cronは止めたままにしておくものだからだ。まだ推測の段階で、悪いパスが良いスナップショットを上書きしてしまうような事態は避けたい。

その仮説を崩す決め手になったのはdubizzleだった。UAEでも屈指の高ボリュームソースであるこのサイトは、その実行中に32,595件の出品を実際に取得していた——まったく健全な数字で、プロキシが機能していることは明らかだった——にもかかわらず、そのほとんどを捨てていたのだ。取得に失敗したのではない。取得した上で、捨てていた。

9月16日：本当のバグを突き止める

ここから、話はプロキシの物語ではなく「行の置き換え」の物語に変わった。私たちの永続化レイヤーは、パスのたびに各ソースの<site>_cars_for_sale.csvをまるごと上書きするスナップショット方式になっている——現行の出品のみを、テーブルごと置き換える。クロールが最後まで完了していれば、これは正しい挙動だ。だが、クロールが途中でタイムアウトし、スクレイパーがそれまでに集め終えた部分的なバッチを「完全なスナップショットであるかのように」書き込んでしまうと、これは破滅的になる。通常9,000件の出品を保持しているソースが、タイムアウトまでに取得できた1,200件で上書きされ、残りの7,800件が消えてしまう——車が売れたからではなく、不完全な取得を完全なものと自分たちのコードが判断してしまったからだ。

プロキシは私たちに嘘をついていたわけではなかった。問題はリトライロジックであり、それは長いあいだ静かに壊れていた。ただ、以前のより健全なプールが、あのスイープが問題になる前にフェッチを完了させてくれていたせいで、見えなくなっていただけだ。

実際に計算してみると、そのスイープのコストは次の通りだった。

1本のURLを諦めるまでに56分。これを1,000を超えるソースに触れるクロール全体に掛け合わせれば、まさに私たちが目にしたような、静かでむらのある失敗が生まれる——一部のソースは無事だが、102ソースはズタズタにされ、ログには「プロキシ障害」と叫ぶものは何もない。なぜなら、技術的にはプロキシ障害など起きていなかったからだ。

9月25日：修正、そしてあなたにとって重要な部分

9日後にリリースされたパッチは、地味ながら2つのことを行った。1つはリトライの計算に上限を設け、詰まったフェッチが1時間近くを食いつぶす前に素早く諦めるようにしたこと。そしてもう1つ——これこそが実際にデータ損失を防ぐ変更だが——部分的なフェッチがもはや行セット全体を置き換えなくなったことだ。あるソースが通常9,000件の出品のうち1,200件しか取得できなかった場合、その一部で上書きするのではなく、直前の完全なスナップショットを保持するようにした。同じ日に、もう1つの変更もリリースされ、監視が誰かにページを送る前にチェックする、目に見えるCRAWL_PAUSEDフラグが書き込まれるようになった——これにより、意図的な一時停止が古いアラートではなく、一時停止として正しく認識されるようになった。

中古のヒュンダイを探しているだけの読者が、なぜこんな話を気にする必要があるのか。それは、私たちが公開している「市場価格より割安」のフラグ——今週時点でサイト上に12,823件が公開中——が正直な表示であるためには、ある出品を比較する対象のコホートが、タイムアウトで切り詰められた断片ではなく、本物の、完全な地域市場でなければならないからだ。比較対象セットの4分の3を失ったスナップショットをもとに組み立てた「お得」バッジは、お得バッジではない。緑色のラベルをまとったノイズにすぎない。そんなものを公開するくらいなら、私たちは9日間クロールを止めておく方を選ぶ。

今日時点のデータセットは、73地域・1,375ソースにまたがる1,108,535件の出品で構成されている——この一件が始まる前よりも大きく、プロキシは更新され、行置き換えのバグも塞がれた状態だ。だが、私が何度も立ち返ってしまう数字は、合計件数ではない。84,401——プロキシ層では健全に見えたクロールと、実際に健全だったクロールとの間にあった、その差だ。