SNS APIのページング処理は再試行を入れないと止まる

この記事では、SNSのAPIでフォロワー一覧のような大量データをページングで取得するときに、再試行を入れていないと処理全体が落ちるという話を書きます。実際に InvokeTimeoutError で止まった経験と、そのとき例外の中身が空でログが役に立たなかった件、そこから入れた2つの対策をまとめます。

ページングは「1回失敗したら全部落ちる」構造になっている

フォロワー一覧のような大量データは、一度のリクエストでは取り切れないのでページングで取得します。これ自体は当たり前の話なのですが、運用してみると問題は件数が増えたときに出てきます。

1,000人を超えると、取得は10回以上のリクエストになります。つまり、10回以上の通信のうち途中で1回でも失敗すると、そこで例外が上がって処理全体が落ちます。1回あたりの失敗率が低くても、回数が増えれば全体としてどこかで踏むことになります。ページングを素直に while で回しただけのコードは、この構造をそのまま抱えています。

実際に InvokeTimeoutError で止まった

実際に止まったときの例外は InvokeTimeoutError でした。名前のとおり呼び出しがタイムアウトしたということは分かりますが、問題はそこから先です。

そのとき私のログには例外を str(e) で記録していました。ところがこの例外は str(e) が空文字でした。結果、ログに残ったのはエラーが起きたという事実だけで、何が起きたのかが分からない状態になりました。ログを見返しても、空文字が1行あるだけです。

# ログに残っていたもの(イメージ)
ERROR: フォロワー取得に失敗しました: 

原因が分からないまま、まず「落ちないようにする」ことと「次に落ちたときに分かるようにする」ことの両方が必要だと判断しました。

対策1:ページング呼び出しを再試行でくるむ

ページングのAPI呼び出しを、再試行つきの関数でくるみました。待ち時間は10秒・20秒・30秒と伸ばし、最大4回まで試します。

waits = [10, 20, 30]  # 4回目まで試す(初回 + 3回の再試行)

for i in range(4):
    try:
        return call_api(cursor)
    except Exception as e:
        if i == 3:
            raise
        log_error(e)
        sleep(waits[i])
  • 1回の失敗で処理全体が落ちる、という構造をここで切ります
  • 待ち時間を伸ばすのは、即座に再試行しても同じ結果になる場合を想定してのことです
  • 4回試してもだめなら、そこは素直に落とします

なお、この待ち秒数と回数が最適かどうかは分かっていません。私の環境で止まらなくなったという以上のことは言えません。

対策2:ログに型名とトレースバックの最後の1行を入れる

今回いちばん効いたのはこちらです。str(e) だけを記録していると、中身が空の例外に当たった瞬間に手がかりが完全になくなります。実際にそうなりました。

そこで、ログには必ず次の2つを入れるようにしました。

  • 例外の型名(今回でいえば InvokeTimeoutError
  • トレースバックの最後の1行
log_error(
    "type=" + type(e).__name__ +
    " msg=" + str(e) +
    " tb=" + traceback.format_exc().strip().splitlines()[-1]
)

型名が残っていれば、メッセージが空でも「何の例外か」は分かります。トレースバックの最後の1行があれば、どこで起きたかの手がかりになります。逆に言うと、この2つを入れていなかったために、最初の障害では原因の切り分けができませんでした。

まとめ

  • フォロワー一覧のような大量データはページングで取得するため、1,000人を超えると10回以上のリクエストになります
  • その構造上、途中で1回失敗すると処理全体が落ちます
  • 実際に InvokeTimeoutError で処理が止まりました
  • そのとき str(e) が空文字だったため、ログを見ても原因が分かりませんでした
  • 対策1:ページング呼び出しを再試行でくるむ(10秒・20秒・30秒と待って4回まで)
  • 対策2:ログに例外の型名とトレースバックの最後の1行を必ず入れる
  • str(e) だけを記録すると、中身が空の例外に当たったときに手がかりを完全に失います