本記事はシリーズとなっております。前編と中編は以下。
【前編】
【Scrapyクローラログ】クローリングにおけるログ出力の考え方【前編】
【中編】
【Scrapyクローラログ】クローラログ設計ベストプラクティス【中編】
目次
- こんにちは!
- ログ出力は
middleware.py
に実装すべし! - ログの実装方法概観
- 【悪手1】 都度ログ
- 【悪手2】 ログ用ラッパー関数を用いる
- 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のアーキテクチャ概観です。
図中の青紫の部分に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の内製化等、挑戦したい試みがあればぜひご一報ください!