意図せずエラー爆撃をしてしまった話

この記事は、本番環境などでやらかしちゃった人 Advent Calendar 2023 の16日目です。

2年ほど前にDiscord Bot開発でやらかした話です。

背景

使用言語: Python
使用ライブラリ: discord.py

複数のDiscord Botが接続してサービスを提供するプロジェクト（詳細は省きます）で事は起こりました。
そのプロジェクトでは、Bot同士がデータをやり取りするために、それ専用として作られたサーバーのチャンネルに決められた形式でJSONデータを送受信しています。

そのとき開発していたBotは、3日前に大規模な改修作業と機能追加を行なったばかりでした。そのときに滅茶苦茶なバグが作られてしまったのです。

何が起こったか

まず、受信したデータはこのような形でした。（一部省略）

{
  "type": "message",
  "//": "省略",
  "reference": 1234567890
}

reference は、同チャンネルにあるJSONデータ内部て定義されているIDです。本来の仕様では、reference の型は int ではなく str でした。
reference が存在する場合、同チャンネル内にあるJSONデータを最新のものから1000件forで回して、記載されているIDが一致するものを探すという実装にしていました。
このとき、型チェックを行なっていなかったので次のような状態になりました。

mid: str = data[reference]  # strを想定していたが、実際にはintが代入される
p_data: DataType
for msg in messages:
    if mid == msg.id:  # intとstrを比較。当然False
        p_data = # 処理
        break

# p_dataを使った処理

つまり、メッセージは存在しているのに存在していないことにされた¹わけです。

最初のエラーの発生

参照先のメッセージが見つかった場合、処理をしたデータを p_data に代入しています。そして、その後に p_data を使って別の処理をしていくわけですが、ここで問題発生。
そう、参照先メッセージが見つからなかったときの処理が無いのです。
そんな中で p_data を使おうとすると何が起きるか。当然 UnboundLocalError である。

次のエラーの発生

さて、そうしてエラーが発生したわけですが、今度はエラー処理にも問題がありました。

このエラー処理でエラーメッセージを送信するときは、テキストではなくEmbedで送信されるようにしています。というより、基本的にBotのメッセージはEmbedを使用しています。
では、エラーメッセージはどこに送信されるでしょうか？ そう、エラーの原因となったメッセージが送信されたチャンネル、つまりJSONデータの受け渡しのためのチャンネルです。

Embedのみのメッセージの content は空になっています。このときに json.loads を message.content を引数に実行²しようものなら当然 JSONDecodeError が発生します。
しかし、流石に不正なデータを受信することは想定していた（そのわりには型チェックを怠ってたよね？）ので、JSONDecodeError は握り潰すようになっていました。

ではエラーが発生せず何の問題もないのでは？ とお思いかもしれません。そう、データの解析処理では型チェック忘れ以外には問題がなかったのです。
問題があったのは、ログ処理なのです。

そのプロジェクトで送受信されるデータはDiscordのチャンネルに保存されています。つまり、後からいくらでも削除できるのです。
そのため、削除されてもいいように受信したデータをログとして自分のサーバーのチャンネルに転送しています³。
その転送処理では、message.content を文字通りそのまま転送していました。しかし、自分が送信したエラーメッセージを受信したとき、そこに送信すべき message.content はありません。Embedだけなのです。
あくまでもJSONデータを送受信するだけだったので、Embedのみが送信されること、つまりは message.content が空であることを想定していませんでした。
空の message.content を送信するとどうなるか。これは「メッセージの内容がない」ということであり、ありえないこと⁴です。
そんなものを送り付けられたサーバーは「こんなの食えたもんじゃねぇ！」と皿を投げてきます。あぁ～！ HTTPException(Cannot send an empty message) の音ォ～！！

エラーは続くよどこまでも

さて、前述のとおり自身が送信したエラーメッセージによってエラーが発生してしまいました。
そう、エラーが発生してしまったのです。

コブラ「エラーが発生した」
ジェフ「エラーが発生するとどうなる？」
コブラ「知らんのか」「エラーが発生する」

エラーが発生したので、エラーメッセージが送信されます。
どこに？ ええそうです、原因となったメッセージのあるJSONデータの送受信用チャンネルに、です。
そして無限ループ

終焉

最初にエラーメッセージが送信された時刻は11:30:00、最後に送信されたのは11:48:14でした。つまり、約18分間もエラーメッセージを送信し続けたというわけです。
件数を数えたところ、全部で1053件、1秒あたり約0.96件でした。18分間も暴れたわりには少ない気もしますが、送受信にかかる時間を考えれば妥当でしょう。
ちなみに、連鎖が止まった要因はログを見る限りDiscord側からの切断だと思われます。

被害

そのプロジェクトに参加している多くのBotが落ちました。要因は大量のエラーメッセージに対し解析エラーを大量に送信したことによるDiscord側からの切断でした。
また、落ちなかったものの大量のエラーメッセージを受信したことにより動作が重くなり、再起動を余儀なくされたBotもありました。

対処

対処の概要

発生から数時間以内に、問題のあった箇所を見つけ暫定的な処置と機能の無効化を行いました。
その後2日かけてバグの修正を行い、Bot側の対処を完了。
また、修正版のデプロイ後にインシデント報告書を作成し、プロジェクト管理者に提出しました。

修正内容

まず、解析処理に型チェックを追加。次に、データの転送時に message.content が空であれば弾くように修正。そして、データ送受信チャンネルでエラーが発生してもエラーメッセージがそのチャンネルに送信されないよう対策を行いました。
これでバグの原因となったものは全て修正できたのですが、無限エラーがまた起きないとは限らないので、エラーメッセージ送信処理に上限を設けました。

何が問題だったか

このやらかしに関わった問題は大きく分けて2つです。

1. 型のチェック漏れ

とりあえず外部から受け取ったデータの型は確認すべきです。教訓。
また、受信したJSONデータを json.loads で dict に変換するという実装でしたが、そもそもフォーマットは決まっていたので専用のクラスを作成した方が安全だったと思います。見た目的にもその方が綺麗だと思います。

2. エラー処理が雑

エラーメッセージを表示することは悪くありません。しかし、エラーメッセージを表示すればそれでいいというわけではありません。
エラーはその一回のみとは限りません。この例のように一度処理を止めないと回復しない場合もあります。例えば、エラーカウンターを実装して、閾値を超えたら自動的に再起動するなどといった対策が考えられます。
また、この例に限っては自身のメッセージに起因するエラーは握り潰すなどの対策も可能でした。

まとめ

• Pythonのような動的型付け言語では型を意識しよう。しないと死ぬ
• エラー処理はやった感を出すのではなくちゃんとやろう

1. もっとも、この場合は型が合っていても参照先メッセージが見つからない（1000件以内に無い）場合も同様のバグが発生したと考えられます。 ↩

2. 自分が送信したデータは自分で受信せずそのまま処理することも当然可能ですし、JSONのエンコード・デコードをすることを考えればその方が効率的です。
   しかし、どうしても送信には時間がかかり、場合によっては他のBotとデータを処理する順番が違ってしまうということも考えられます。そのプロジェクトではそうなってしまっても大きな問題は発生しないのですが、個人的に気に食わないので自分で送信したデータも受信して処理するようにしています。 ↩

3. 結局削除できるよね？ という突っ込みは無しでお願いします。
   ちなみに、データの送受信チャンネルの中身が消されるといったインシデントもあったのですが、僕の話ではないので詳細は書きません。ログ取りが一応役に立っています。 ↩

4. 添付ファイルやEmbedがある場合は別です。 ↩