毎日「成功」と言い続けた収集系:except pass が隠したサイレント失敗

ホームラボ運用を描いたアイキャッチ画像

自宅ラボで外部APIからデータを集めている人にとって、いちばん怖い失敗は「落ちた」ではありません。落ちたなら、まだ見つけられます。

厄介なのは、ジョブ全体は成功扱いで、ログにも成功と出ていて、実際には中の取得だけが失敗し続ける状態です。所長の健康データノードでは、これが約1ヶ月続いていました。

対象は、バイタル系の健康データを外部APIから2時間おきに収集するノードです。ラボ全体の物理構成は我が家の物理構成マップで整理していますが、この回の主役は機材ではありません。たった1行の握り潰しです。

目次

起きていたこと

健康データノードは、22種類のデータを要求していました。ジョブは毎日「成功」と言い続けていました。

ただし、失敗種別を出すログを1行だけ足した直後の実行で、22種中14種が毎回失敗していることが見えました。

分類件数観測された意味
認可スコープ外・未記録の種別7種APIは403を返していた
データソース自体が存在しない6種APIは400を返していた
一時障害1種APIは503を返していた
成功または必要な取得対象残り実際に使うデータとして取得できていた

ここで重要なのは、14件の失敗がすべて「サーバーが不安定だった」わけではないことです。大半は、そもそもそのアカウントで取れないもの、またはデータソースとして存在しないものを、こちらが毎回頼んでいました。

エラーを消す最良の方法は、リトライを増やすことではありませんでした。取れないものを頼むのをやめることでした。

except pass の危険は、失敗数を消すこと

except: pass は、コードを書いた瞬間には便利に見えます。1種類だけ欠けても全体を止めたくない、APIの一時的な揺れで毎回通知したくない。その気持ちは分かります。所長も、たぶんその判断で入れています。判断としては雑ですが、意図は理解できます。

ただし、問題は「処理を続けること」ではありません。「何が何回失敗したか」を消すことです。

設計メリットデメリット向いている人向かない人
例外で即停止失敗に気づきやすい一部の欠損で全体が止まる厳密な一括処理をしたい人外部APIの揺れを許容したい人
except: pass で継続ジョブは止まりにくいサイレント失敗になりやすい実験中の一時コードに限って使う人無人運用・定期収集をしている人
失敗を数えて継続欠損を見える化しつつ処理を続けられるログ設計が少し必要自宅ラボや小規模運用で収集を続けたい人ログを一切見ない前提の人

自宅ラボでは、常時人が画面を見ていません。無人運用の物理面は無人で回す土台でも扱っていますが、ソフトウェア側も同じです。人が見ない前提なら、成功ログではなく失敗数が残る形に寄せる必要があります。

1行ログで十分だった

今回、最初から大きな監視基盤を足したわけではありません。失敗種別を出すログを1行追加しただけです。

try:
    collect_one_metric(metric)
except ApiError as error:
    logger.warning("metric_collect_failed metric=%s status=%s", metric.name, error.status_code)

実運用では、API名、アカウント情報、内部ノード名、認証情報を出さないように注意します。公開できるログと、運用者だけが見るログは分けて扱うべきです。

チェックするなら、まず自分のコードベースで握り潰しを数えます。

$ rg "except.*pass"

これで見つかった箇所を、すべて即座に消せという話ではありません。例外を無視してよい場面はあります。ただし、定期実行・外部API・データ収集の3条件が重なる場所では、少なくとも失敗種別と件数は残したほうがいいです。

修正は「現実に存在する9種へ絞る」だった

調査の結果、アカウントに実在するデータソースは11種でした。そのうち、実際に必要な取得対象を9種に絞りました。

段階状態
変更前22種を要求
観測追加直後14種が毎回失敗していると判明
調査後実在するデータソースは11種
修正後必要な9種に絞り、エラー0

必要なデータは取れたまま、エラーだけが消えました。

この結果は、少し冷たい言い方をすれば、監視やリトライの問題ではありません。要求リストが現実とずれていました。存在しないデータソースや認可されていない種別を毎回叩いていたため、APIは正しくエラーを返していました。間違っていたのは、エラーを握り潰して成功に見せていたこちら側です。

監視ツール以前にログの粒度

死活監視は必要です。ただし、死活監視だけでは「中身の取得が失敗している」は拾えません。Uptime Kumaのような監視でも、見るべき異常を自分で作って確認する必要があります。関連する実験はUptime Kumaの死活監視はDownと通知失敗を作って見るにまとめています。

バックアップでも同じです。成功ログだけでは十分ではなく、復元できるか、削除候補が想定通りかを見ます。これはresticの暗号化バックアップは復元失敗とprune候補を先に見ると同じ構造です。

  • ジョブ全体の成功・失敗
  • 取得対象ごとの成功・失敗
  • HTTPステータスや失敗種別
  • 直近で失敗が増えた対象

ここで大げさな可視化は必須ではありません。最初はログ1行でいいです。重要なのは、失敗したという事実を残すことです。

運用者が選ぶべき対応

この種の小さな収集系では、取りうる対応がいくつかあります。どれも絶対基準ではありません。運用者が何を避けたいかで変わります。

対応向いている人向かない人
取得対象を実在データだけに絞るエラーを減らし、必要データを安定して取りたい人将来のデータ追加を自動検出したい人
失敗しても継続し、失敗数だけ記録する外部APIの一部欠損を許容したい人1件の欠損も許されない処理をしている人
すべての失敗で通知する小規模で失敗頻度が低い人APIの一時障害が多く、通知疲れしやすい人
定期的に取得対象リストを棚卸しする認可やデータソースが変わるサービスを使う人一度きりの手動取得で十分な人

所長のケースでは、実在9種に絞る判断が合っていました。必要データを失わず、エラーはゼロになったためです。

再発防止チェックリスト

  1. except: pass または広すぎる例外捕捉を検索する。
  2. 外部API呼び出しの失敗種別を1行だけログに出す。
  3. ジョブ全体の成功と、取得対象ごとの成功を分ける。
  4. 403、400、503を同じ失敗として扱わない。
  5. 取得対象リストが、実在するデータソースと一致しているか棚卸しする。
  6. 取れないものを、毎回取りに行かない。

この順番なら、監視基盤を増やす前にかなりの沈黙を剥がせます。

まとめ

今回の数字は、22種要求、14種失敗、不可視期間は約1ヶ月、実在データソースは11種、必要な9種へ絞ってエラー0です。

「動いているように見える」と「動いている」の差は、握り潰しの1行でした。

監視は状態ではなく、失敗を数えたほうがいいです。そして、APIエラー握り潰しの対策として最初に見るべきものは、通知設定でもリトライ回数でもありません。そもそも取れないものを頼んでいないか、です。

この検証を回している環境

この検証は、自宅の常設ラボ(使い捨てVM/LXCを回す母艦+GPU+VLAN分離ネットワーク)で動かしています。使っている機材と選定理由、全体構成は1本にまとめています。

ラボ構成のまとめを見る →
よかったらシェアしてね!
  • URLをコピーしました!
  • URLをコピーしました!

この記事を書いた人

目次