【Scrapyクローラログ】クローラログ設計ベストプラクティス【中編】

※本記事は【Scrapyクローラログ】のシリーズ中編です。前編は「[【Scrapyクローラログ】クローリングにおけるログ出力の考え方【前編】](https://qiita.com/realmadridmarcelo/items/b4a8a183682efcf68d13)」となっております。


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

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

# 初めまして
株式会社 Panta Rhei CEOのかずです。[Pandasista](https://x.com/sotsogprinciple)というハンネでツイッターをやっています。pandas大好きです。データも好き。

![IMG_0587.JPG](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/540865/4df3af57-b0b2-6061-682e-68e174192f26.jpeg)
# Qiita Engineer Festa2024でマラソンを完走したい

[Qiita Engineer Festa 2024](https://qiita.com/official-campaigns/engineer-festa/2024)という素敵なイベントがあります。

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

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

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

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

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

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

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

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

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

![scrapy_architecture_02.jpeg](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/540865/b549a0e8-7e98-d2aa-656f-fd64a807002c.jpeg)
*[Scrapyのアーキテクチャ概観](https://doc-ja-scrapy.readthedocs.io/ja/latest/topics/architecture.html)*

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

上記の表ではScrapyクロールフローに沿ったエラー発生しやすいポイントをまとめました。
要約すると
- <B>クエストを送る時</B>
- <B>レスポンスを解析する時</B>
- <B>DBやストレージに格納する時</B>

にエラーが頻発します。

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

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

クローリング中によく見るステータスコードは[この記事](https://qiita.com/realmadridmarcelo/items/91fd0df0c55bf4591a8c)にまとまっています！

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

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

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

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

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

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

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

出典: [Loggin HOWTO](https://docs.python.org/ja/3/howto/logging.html)

他の例では、INFOとWARNINGの間にNOTICE(正常であるが重要な状態)というレベルがあったり、最上位にEMARGENCE(システムが破壊的に利用不可能な状態)といったレベルがあるそうです。([参考](https://qiita.com/tadashiro_ninomiya/items/19c774898c68add6185e#%E3%83%AD%E3%82%B0%E3%81%AE%E3%83%AC%E3%83%99%E3%83%AB%E3%81%A8%E6%84%8F%E5%91%B3))
本記事ではScrapyでのロギングがスコープなため、Pythonの標準モジュールで指定される上記5つのレベルをクローラの各事象に当てはめていこうと思います。

# 【本題】 クローリングにおけるログ設計
ここまで読めばクローリングに関してのログ設計の下準備ができています。

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


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

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

クローリングにおいて```CRITICAL```な事象は「<B><font color='red'>想定以上にプログラムが実行し続ける</font></B>」です。
なぜならば、
- <B>同じデータをDBやストレージを入れ続ける</B>
- <B>クラウドのDBやストレージと永遠にInput/Ouptutし続ける</B>
- <B>クロール先に想定以上の負荷をかけてしまう</B>

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

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

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

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

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

【ケーススタディ】 ~食品系や関連物流系、小売などにアタックするための営業リスト作成用クローラ~
この手の業界は、その商習慣から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```にしちゃっています。

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

です。

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

ここまで長かった...

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

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