※本記事は【Scrapyクローラログ】のシリーズ中編です。前編は「【Scrapyクローラログ】クローリングにおけるログ出力の考え方【前編】」となっております。

元々「Scrapyにおけるログ出力設計のベストプラクティス【ログはMiddlewareに書こう】」という記事を書こうとしてました。が、かなり長くなってしまったので分割しました。
後編でScrapyのログに関する実装をまとめます。

初めまして
Qiita Engineer Festa2024でマラソンを完走したい
結論
クローリングではエラーは当たり前
クローリングでエラーが発生しやすいポイント
Pythonにおける「ログレベル」
【本題】クローリングにおけるログ設計
1. CRITICAL
2. ERROR
3. WARNING
4. INFO
5. DEBUG
まとめ

初めまして

株式会社 Panta Rhei CEOのかずです。Pandasistaというハンネでツイッターをやっています。pandas大好きです。データも好き。

Qiita Engineer Festa2024でマラソンを完走したい

Qiita Engineer Festa 2024という素敵なイベントがあります。

その中で投稿マラソンという素敵なコースが！！！
なんと「38記事書けば素敵な景品がもらえる！！」らしいです。

1日1記事でギリギリ達成です。
本日は4報目！！！
3日サボったので1日2報をしばらく心がけようと思います。
なかなかネタが無いようであるので、いっぱい書けそうです！
ただ、1記事にいっぱい書きすぎちゃうと1日の時間がなくなってしまうので程よい粒度にできらたと思っています。
みなさんの参考になるような弊ナレッジを少しでもお裾分けできたら幸いです！

結論

結論から先に申し上げます。

CRITICALは処理が永遠に続きそうな時に用いよう！
ERRORはHTTP/HTTPSリクエスト時, 取得要素解析時, データ格納時につけよう！
WARNINGは取得したい(が取得できるとは限らない)データが取得できなかった時につけよう！
INFOはデータリクエスト時及びデータ格納時のそれぞれ各挙動につけよう！
DEBUGはよしなにつけよう！

クローリングではエラーは当たり前

「予測できるエラーはエラーでは無い」という言葉があります。これは「予測できるならあらかじめ対策しておけよ！」という戒めの言葉ですが、ことクローリングに関してはこれが当てはまりません。

なぜならどんなに完璧なクローラでもデータアーキテクチャでも、クライアント(=クロール先のサイト)の仕様変更でエラーが発生してしまうからです。

クローリングでエラーが発生しやすいポイント

クローリングをしていると良くエラーが発生します。

想定外のステータスコードを持ったレスポンス
データ格納先のDBやストレージにアクセスできない
\nや\rを多く含むテキスト要素により、意図しない改行が発生しcsvパースを失敗する

といった形です。エラーを発生しやすいポイントをクローラフローからまとめてみます。
クローリングの流れは以下のScrapy公式ドキュメントにあるアーキテクチャ概観が最も上手く表現している(個人的な信念)ので拝借しました。

Scrapyのアーキテクチャ概観

Step	Scrapyコンポーネント	説明	エラーが発生しやすいポイント
1	Spider	SpiderはクロールするURLの最初のリクエストを生成しEngineに送信
2	Engine	EngineはSpiderからリクエストを受け取りSchedulerに転送
3	Scheduler	Schedulerはリクエストをキューに入れ、処理するタイミングでEngineに返送
4	Engine	EngineはリクエストをDownloaderに渡す	◎
5	Downloader	Downloaderはインターネットからページを取得し、Engineにレスポンスを送る
6	Engine	Engineはレスポンスを受け取り、Spiderに送ってxpathやselectorによる解析を実行
7	Spider	Spiderはレスポンスを処理し、Itemと追加のリクエストを抽出し、それらをEngineに返却	◎
8	Item Pipeline	Spiderが抽出したItemは、処理と保存のためにItemPiplineを経由しDBやストレージへ	◎

上記の表ではScrapyクロールフローに沿ったエラー発生しやすいポイントをまとめました。
要約すると

クエストを送る時
レスポンスを解析する時
DBやストレージに格納する時

にエラーが頻発します。

エラーポイント1 ~ リクエストを送る時 ~

これは分かりやすいです。
ステータスコード200が返ってこない時です。
429(Too Many Access)が返ってきたりすると悲しいです。これは割と対応の仕様がないです。

クローリング中によく見るステータスコードはこの記事にまとまっています！

エラーポイント2 ~ レスポンスを解析する時 ~

これは何をエラーとするかを厳密に定義しないといけないです。
ここでの定義は「取得を意図しておりかつ取得できるはずの要素が取得できていない」ということになります。
従って、そもそもそのクロール先に意図した要素がないために返ってくるNoneと、要素があるのに返ってくるNoneは全然違うということです。後者はエラーです。

エラーポイント3 ~ DBやストレージに格納する時 ~

データベースに格納する時、スキーマと違うデータが来たのでINSERTできなかった、とかcsvのパース失敗でバルクインサートができなかったなどのエラーが発生します。

Pythonにおける「ログレベル」

Pythonの標準モジュールであるloggingには、発生した事象によってログ出力を5段階に分ける思想を持っています。

レベル	いつ使うか
DEBUG	おもに問題を診断するときにのみ関心があるような、詳細な情報。
INFO	想定された通りのことが起こったことの確認。
WARNING	想定外のことが起こった、または問題が近く起こりそうである (例えば、'disk space low') ことの表示。
ERROR	より重大な問題により、ソフトウェアがある機能を実行できないこと。
CRITICAL	プログラム自体が実行を続けられないことを表す、重大なエラー。

出典: Loggin HOWTO

他の例では、INFOとWARNINGの間にNOTICE(正常であるが重要な状態)というレベルがあったり、最上位にEMARGENCE(システムが破壊的に利用不可能な状態)といったレベルがあるそうです。(参考)
本記事ではScrapyでのロギングがスコープなため、Pythonの標準モジュールで指定される上記5つのレベルをクローラの各事象に当てはめていこうと思います。

【本題】クローリングにおけるログ設計

ここまで読めばクローリングに関してのログ設計の下準備ができています。

クローリングにおいてログ設計とは「何をERRORと置いて、何をWARNINGと置くか」が本質となります。
以下に上記のログレベルに従ってログを設計して整理していきます。

CRITICAL

クローリングで言うと、正直ログレベル説明であるような「プログラム自体が実行を続けられないこと」はCRITICALかどうかは議論が分かれます。ここは取得したデータの目的次第です。

例えば、クローリングしたデータを加工して顧客に提供するような場合、データが取得できないことはすなわち仕入れができない状況に等しいため、かなりCRITICALです。一方、クローリングしたデータを自社の意思決定に使う場合や、分析等に使う場合であればCRITICALというにはやりすぎです(個人的にはこれでもCRITICALですが、上記の例と比較すると重大さは下回ります)。

クローリングにおいてCRITICALな事象は「想定以上にプログラムが実行し続ける」です。
なぜならば、

同じデータをDBやストレージを入れ続ける
クラウドのDBやストレージと永遠にInput/Ouptutし続ける
クロール先に想定以上の負荷をかけてしまう

ということで、自社のクラウドやマシンコストを消費し続けてしまい、かつ先方にも迷惑を結果となるからです。

ここら辺は、「想定クロール時間を計測しておいて、そこから10倍の時間が経過してもなおクロールが続いていればCRITICALを出す」などの運用を検討しましょう。無論処理強制停止コードも入れておくのはマストです。

ERROR

ERRORは前述のloggingの公式ドキュメントには「より重大な問題により、ソフトウェアがある機能を実行できないこと。」とあります。クローラログにおいては、取るべき正しいデータ(取得を意図しかつ取得できる要素)を取得できない状態について、ERRORをつけると考えるのが良いです。

これをざっくり言うと「エラーが発生しやすいポイント」で紹介した3点を実行するPythonのコードブロックにtry/exceptを付ければいいだけです。exceptのコードブロックにlogger.error("時間とかステータスコードとか解析に用いたxpathとか")を付与するような実装になるかと思います。

WARNING

WARNINGが一番難しいです。と言うのも「もう直ぐエラーが起きそう」と言うのは結構想定が難しいからです。
これはすなわち「もうすぐクライアントが仕様変更しそう」みたいなもので、実質無理です。
WARNINGの使い道はの一例としては「ホームページ上からデータを取得する際に、欠損している場合もあるからNoneが送られてくることもあるけど、取得してくれたら嬉しいデータ」となります。

【ケーススタディ】 ~食品系や関連物流系、小売などにアタックするための営業リスト作成用クローラ~
この手の業界は、その商習慣からFaxアプローチが有効な場合があります。
そのため、Fax番号を付与した企業リストが欲しくなります。一方で、Fax番号はすべての企業が持っているわけではありません。そのため、

WARNING: 2024-06-18 4:00:00 +09:00 None stored as FaxNumber

といったログを出すと良い気がします。

INFO

これはすべてのステータスコードと取得要素に出しましょう。

INFO: 2024-06-18 4:00:00 +9:00 (GET) 200 from https://pantarhei.co.jp
INFO: 2024-06-18 4:00:00 +9:00 "kazu@pantarhei.co" stored as MailAddress

こんな形です。

DEBUG

これは開発者がよしなに実装すれば良いかなと思います。
私はここら辺に該当しそうな項目もWARNINGかINFOにしちゃっています。

まとめ

CRITICALは処理が永遠に続きそうな時に用いよう！
ERRORはHTTP/HTTPSリクエスト時, 取得要素解析時, データ格納時につけよう！
WARNINGは取得したい(が取得できるとは限らない)データが取得できなかった時につけよう！
INFOはデータリクエスト時及びデータ格納時のそれぞれ各挙動につけよう！
DEBUGはよしなにつけよう！

です。

次回の【後編】では「Scrapyにおけるログ出力設計のベストプラクティス【ログはMiddlewareに書こう】」と題しまして、Scrapyを用いた実際の実装を書こうと思います。

ここまで長かった...

結言

株式会社 Panta Rheiは、「Everything Analysable ~すべてを分析可能に~」を理念として事業をするアナリティクスカンパニーです。
既存の「経験者によるえいや」や「テーブルデータを用いた構造的な分析」のみならず、AIを用いた定性的な特徴も分析をし、今までにないインサイト発掘に貢献いたします。

もしご興味あれば、ご応募ください！ by pandasista

目次