【Scrapyクローラログ】Scrapyにおけるログ出力 ~ログはMiddlewareに実装すべし~【後編】

本記事はシリーズとなっております。前編と中編は以下。

【前編】
【Scrapyクローラログ】クローリングにおけるログ出力の考え方【前編】
【中編】
【Scrapyクローラログ】クローラログ設計ベストプラクティス【中編】

目次

1. こんにちは!
2. ログ出力はmiddleware.pyに実装すべし!
3. ログの実装方法概観
   1. 【悪手1】 都度ログ
   2. 【悪手2】 ログ用ラッパー関数を用いる
4. middleware.pyの役割

こんにちは！

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

Qiita Engineer Festa 2024という素敵なイベントに参加して、景品目指して記事投稿を頑張っています！
本日は5報目となります！

ログ出力はmiddleware.pyに実装すべし！

本記事を読んでいる方はScrapyに興味があるか、もしくは実際に実装に携わる方だと思います。
Scrapyに関する入門は「10分で理解するScrapy」に解説を譲るとします。(本記事はScrapyバイブルです(個人の感想)。Scrapy version 2.0系の公式日本語ドキュメントがない今(2024-07-06現在)、多くのScrapy入門者の方がこれを参照すると思います。)

結論から言うと、ログ実装はScrapyの

Middleware.pyに記述すべき
です。

ログの実装方法概観

ログにはさまざまな実装方法があります。

• 都度ログを吐き出したいところにlogger.error("hoge")する
• ログをラッパー関数に記述し、各関数やクラスでデコレータとして実装する
  などがあると思います。
  ことScrapyにおいては上記2種類は悪手と言えます。

【悪手1】 都度ログ

これはどんな場所でもアンチパターンになりますね。

logger.info("hoge")

をScrapyの至る所に打っとくイメージです。
保守性最悪ですし再現性も最悪です。

【悪手2】 ログ用ラッパー関数を用いる

これは結構いろんなアプリケーションに採用される実装で、
アプリケーションとかオレオレ関数やクラスがたくさんある環境であればこれは採用候補に上がります。

from logging import getLogger
def logger(f):
    def _wrapper(*args, **keywords):
        logger = getLogger(f.__name__)
        logging.basicConfig(filename='scrape.log', level=logging.INFO)
        logger.info(f'{f.__name__} starts.')
        logger.info(f'OPEN: %(asctime)s')
        v = f(*args, **keywords)
        logger.info(f'CLOSE: %(asctime)s')
        logger.info(f'CLOSE: {v}')
        return v
    return _wrapper

といった形でデコレータ関数を作って、実行したいクローラクラスにつけていきます。

class Crawl(scrapy.Spider):
    name = 'crawl'
    @logger
    def parse(self):
        yield scrapy.Request(url="https://example.com")

みたいな使い方です。
デコレータ関数を作ってしまえばさまざまな関数やクラスに@loggerとするだけで同様の処理が期待できるので再現性(≒再利用可能性)があって良きです。
ただ、このデコレータ関数によるログ実装、Scrapyとは非常に相性が悪いです。
というのも、Scrapyはクローリングフレームワークであり、各関数が高度にモジュール化されています。
そのため、そのモジュール内の各処理にログをつけるということはデコレータでは実現しにくいのです。

例えば「example.comにGETリクエストを送った際のレスポンスをログとして出したい」といった際、Scrapyの実装ではそれが実装できません。
結局各リクエストやパースを関数化してデコレータを付与することになりますが、それだと【悪手1】で記したアンチパターンと同じになってしまいます。

ちなみに、クローラの実装においてログを付けるべき場所について、【Scrapyクローラログ】クローラログ設計ベストプラクティス【中編】に記載しています。

ここまで来て、

• 一つの変更で全てをログを反映
• リクエストやパースそれぞれにログをつけたい

という要件が見えてきます。

middleware.pyの役割

その要件を満たすのが、
Scrapyのmiddleware.pyです。

Scrapyのアーキテクチャ概観

この図はScrapy公式ドキュメントに載っているScrapyのアーキテクチャ概観です。
図中の青紫の部分にMIDDLEWAREが見えるかと思います。
2つあります。

• SPIDERの入出力にいっちょ噛みするMIDDLEWARE
• DOWNLOADERの入出力にいっちょ噛みするMIDDLEWARE

それぞれはクラスとしてScrapy上で事前定義されており、以下のメソッドを持ちます。

クラス	関数名	種別	処理の概要	引数
SpiderMiddleware	from_crawler	クラスメソッド		crawler
SpiderMiddleware	process_spider_input	メソッド		response, spider
SpiderMiddleware	process_spider_output	メソッド		response, result, spider
SpiderMiddleware	process_spider_exception	メソッド		response, exception, spider
SpiderMiddleware	process_start_requests	メソッド		start_requests, spider
SpiderMiddleware	spider_opened	メソッド		spider_opened
DownloaderMiddleware	from_crawler	クラスメソッド		crawler
DownloaderMiddleware	process_request	メソッド		response, spider
DownloaderMiddleware	process_response	メソッド		request, response, spider
DownloaderMiddleware	process_exception	メソッド		request, exception, spider
DownloaderMiddleware	spider_opened	メソッド		spiderspider

この中で

• SpiderMiddlewareはパースしたHTML要素に関するログ出力
• DownloaderMiddlewareはリクエストに関するログ出力
  が最適です。

実装例

本記事では「DownloaderMiddlewareにリクエストログ」を例に、実装例を紹介します。
ここで、ログを実装すべきメソッドはfrom_crawlerです。
from_crawlerは、

scrapy crawl {媒体名}

を実行した時に、一番最初に実行されるメソッドです。
従って、ここにログの出力を記述しておかないと、

• ログの出力漏れ
• クロールのそれぞれのステップでの面倒なログ実装
  を引き起こしてしまいます。

class DownloaderMiddleware:
    # Not all methods need to be defined. If a method is not defined,
    # scrapy acts as if the downloader middleware does not modify the
    # passed objects.
    log_level_by_status_code = {   
        "log_level_by_status_code": {
            "INFO": [
                100, 101, 102,
                200, 201, 202, 203, 204, 205, 206, 207,
                300, 301, 302, 303, 304, 305, 307, 308
            ],
            "WARNING": [
                500, 501, 502, 503, 504, 505,
                506, 507, 508, 510, 511
            ],
            "ERROR": [
                400, 401, 402, 403, 404, 405, 406, 407,
                408, 409, 410, 411, 412, 413, 414, 415,
                416, 417, 418, 421, 422, 423, 424, 425,
                426, 428, 429, 431, 451
            ]
        }
    }
    @classmethod
    def from_crawler(cls, crawler):
        s = cls()
        current_time = datetime.now(timezone('Asia/Tokyo')).strftime('%Y-%m-%d_%H:%M:%S_%Z%z')
        log_directory = f"/var/log/scrapy/{crawler.spider.name}"
        if not os.path.exists(log_directory):
            os.makedirs(log_directory)
        logfile_name = log_directory + "/" + f"{current_time}.log"
        log_settings = {
            "LOG_FILE"          : logfile_name,
            "LOG_FILE_APPEND"   : True,
            "LOG_ENABLED"       : True,
            "LOG_LEVEL"         : logging.INFO,
            # "LOG_FORMAT"        : ,
            "LOG_STDOUT"        : True,
            }
        configure_logging(
            settings=log_settings,
            install_root_handler=True)
        crawler.signals.connect(s.spider_opened, signal=signals.spider_opened)
        return s

上から解説をしていきます。

class DownloaderMiddleware:
    # Not all methods need to be defined. If a method is not defined,
    # scrapy acts as if the downloader middleware does not modify the
    # passed objects.
    log_level_by_status_code = {   
        "log_level_by_status_code": {
            "INFO": [
                100, 101, 102,
                200, 201, 202, 203, 204, 205, 206, 207,
                300, 301, 302, 303, 304, 305, 307, 308
            ],
            "WARNING": [
                500, 501, 502, 503, 504, 505,
                506, 507, 508, 510, 511
            ],
            "ERROR": [
                400, 401, 402, 403, 404, 405, 406, 407,
                408, 409, 410, 411, 412, 413, 414, 415,
                416, 417, 418, 421, 422, 423, 424, 425,
                426, 428, 429, 431, 451
            ]
        }
    }

DownloaderMiddlewareクラスを定義して、どんなステータスコードにどんなログステータスを付与するかを決めています。

    @classmethod
    def from_crawler(cls, crawler):
        s = cls()

@classmethodは「クラスメソッド」と呼ばれるPython標準のデコレータです。
クラスに引っ付いたメソッドをクラスメソッド化します。
詳しくはこちらをご覧ください。

クラスメソッドなので、clsは自前のクラス、すなわちDownloaderMiddlewareそのものです。crawler引数は、その名の通りクローラオブジェクトで、さまざまなメソッドを持っています。

        current_time = datetime.now(timezone('Asia/Tokyo')).strftime('%Y-%m-%d_%H:%M:%S_%Z%z')
        log_directory = f"/var/log/scrapy/{crawler.spider.name}"
        if not os.path.exists(log_directory):
            os.makedirs(log_directory)
        logfile_name = log_directory + "/" + f"{current_time}.log"

1行目は、クロールの時間をログファイル名にするため時間を取得しています。
2~5行目はログファイルのディレクトリ生成やファイル名を指定しています。

        log_settings = {
            "LOG_FILE"          : logfile_name,
            "LOG_FILE_APPEND"   : True,
            "LOG_ENABLED"       : True,
            "LOG_LEVEL"         : logging.INFO,
            # "LOG_FORMAT"        : ,
            "LOG_STDOUT"        : True,
            }
        configure_logging(
            settings=log_settings,
            install_root_handler=True)

ここはログの詳細の設定をする部分です。Scrapyで対応している設定変数はこちらを参考にしてください。

ここで大事になってくるのが、「LOG_DATEFORMATは用いない」という部分です。

Timezoneが設定できません。

これはクローラログではなかなか最悪です。例えば海外のサイトをクロールする際、クローラを乗せるクラウドインスタンスのリージョンはその現地のものにすることがあります。これはクロール先が自国由来のIPしか許していない場合などが原因となります。

そうなると、どのタイムゾーンでクロールをしたかの情報は時間データに付随する形で欲しくなりますね。

取れました(2024/07/02)。(参考)

configure_loggingは「デフォルトのScrapyのログ設定」をいじるための関数です。
settingsの内容を反映しつつ、settingsに無い設定項目はデフォルトを用いてくれるため、非常に使い勝手が良いです。

crawler.signals.connect(s.spider_opened, signal=signals.spider_opened)

signalsは特定のイベントが発生した時にログ出力するようなメソッドとなっています。
ここでは、「spider_openedのMiddlewareを呼び出しながら、signals.spider_openedというイベントが発生したよ」とログ出力しています。

以下のようなログが出力されます。

2024-06-27 17:38:44 [scrapy.core.engine] INFO: Spider opened

まとめ

• パースに関するログ出力はmiddlewares.pyのSpiderMiddlewareクラスのprocess_spider_outputメソッドに実装しよう!
• リクエストに関するログ出力実装はmiddlewares.pyのDownloaderMiddlewareクラスのfrom_crawlerクラスメソッドに実装しよう!

となります。

結言

株式会社 Panta Rheiでは「Everything Analysable」を標榜とし、世の中にあるあらゆる定性的な対象をAIによって定量化する事業をおこなっております。
AIに召し上がっていただく綺麗なデータを作る、データフローを整形するなどの課題や、そもそものAIの内製化等、挑戦したい試みがあればぜひご一報ください！