1. 为什么日志是爬虫项目从玩具走向生产的分水岭刚接触 Scrapy 那会儿我写爬虫基本靠print。请求发出去了print(开始请求)解析出数据了print(item)报错了print(出错了)。在本地跑几十条数据的时候这套土办法确实够用屏幕上刷刷滚动的输出甚至让人有种掌控全局的错觉。可一旦把爬虫丢到服务器上跑或者数据量上到几万条print的致命缺陷就暴露无遗了你根本不知道哪条输出对应哪次请求不知道错误发生在哪个时间点更没法把不同级别的信息分开看。屏幕一关所有线索全断。Scrapy 内置的logging模块就是来解决这个问题的。它基于 Python 标准库的logging构建但做了针对爬虫场景的深度定制把日志分成了几个清晰的层级并且和 Scrapy 的各个组件引擎、调度器、下载器、Spider、Pipeline天然打通。换句话说你不需要自己造轮子只要理解它的规则就能让爬虫在无人值守的情况下把发生了什么、什么时候发生、严重程度如何完整记录下来。这篇文章面向的是已经能跑通基础 Scrapy 爬虫、但被日志问题困扰的开发者。我会从日志的层级设计讲起拆解settings.py里那几个关键配置项的真实作用然后给出文件日志、按时间切割、按级别分流这几套实战方案最后聊聊我在实际项目里踩过的坑——比如日志把磁盘写满、重复输出、编码乱码这些让人头大的问题。看完之后你应该能给自己手头的爬虫配上一套清晰、可控、可追溯的日志系统。2. Scrapy 日志体系的层级设计与默认行为2.1 五个日志级别到底该怎么选Scrapy 沿用了 Python 标准库的日志级别从低到高分别是DEBUG、INFO、WARNING、ERROR、CRITICAL。很多人配日志时随手写个LOG_LEVEL INFO就完事但其实每个级别在 Scrapy 里都有约定俗成的使用场景理解这些约定能帮你快速定位问题。DEBUG是最啰嗦的级别Scrapy 会把每一次请求的调度、每一个 Item 的进出、每一次中间件的调用都打出来。默认情况下 Scrapy 是不开DEBUG的因为一个中等规模的爬虫跑起来DEBUG 日志能瞬间刷屏。但当你需要排查为什么这个请求没发出去为什么这个 Item 被丢弃了这类问题时临时把级别调到 DEBUG 是最快的手段。INFO是 Scrapy 的默认级别也是生产环境最常用的。它会记录爬虫启动、关闭、统计信息、以及每个请求的成功响应。你看到的那些DEBUG: Crawled (200) GET ...其实在 INFO 级别下会被过滤掉一部分只保留关键节点。WARNING表示有问题但不致命比如重试、被反爬拦截、响应状态码异常。ERROR表示这次操作失败了比如解析异常、Pipeline 报错。CRITICAL则是整个爬虫要挂了比如无法连接数据库、磁盘写满。我的经验是开发调试期用 DEBUG上线初期用 INFO稳定运行后可以调到 WARNING 以减少日志量。这个切换不需要改代码改一行配置就行。2.2 Scrapy 默认把日志打到哪里去了很多人以为 Scrapy 的日志默认输出到文件其实不是。Scrapy 默认是通过logging.StreamHandler把日志打到标准错误流stderr也就是你的终端屏幕上。这就是为什么你在命令行跑爬虫时能看到满屏输出但关掉终端后什么都留不下。这个默认行为由settings.py里的LOG_ENABLED和LOG_STDOUT两个配置控制。LOG_ENABLED默认为True表示开启日志LOG_STDOUT默认为False表示日志走 stderr 而不是 stdout。这里有个细节值得注意如果你把LOG_STDOUT设为True日志会和print的输出混在一起这在调试时反而容易乱。我一般保持默认让日志和业务输出分开。另外Scrapy 在启动时会自动配置一个根 logger名字就叫scrapy。你通过logging.getLogger(__name__)拿到的 logger 会继承这个根 logger 的配置。理解这一点很重要因为它决定了你自定义的 logger 会不会和 Scrapy 的默认输出重复。2.3 日志格式里每个字段的含义Scrapy 默认的日志格式长这样2024-01-15 10:23:45 [scrapy.core.engine] INFO: Spider opened拆开看2024-01-15 10:23:45是时间戳[scrapy.core.engine]是产生日志的组件名INFO是级别后面是具体消息。这个格式由LOG_FORMAT配置项控制默认值是%(asctime)s [%(name)s] %(levelname)s: %(message)s。这里有个容易被忽略的点%(name)s拿到的是 logger 的名字而不是类名。Scrapy 内部会为每个组件创建独立的 logger比如scrapy.core.scraper、scrapy.extensions.throttle等。当你在日志里看到某个组件疯狂输出时就能快速判断是哪个环节出了问题。比如scrapy.extensions.throttle频繁出现说明你的爬虫被限速了scrapy.downloadermiddlewares.retry频繁出现说明重试次数偏高。如果你想让日志带上日期以外的信息比如进程 ID 或者线程名可以自定义LOG_FORMAT。但要注意格式字符串里的字段必须是logging模块支持的写错了会导致日志直接报错。3. settings.py 里那几个决定日志去向的关键配置3.1 LOG_FILE 与 LOG_ENCODING 的配合把日志写到文件最直接的方式就是设置LOG_FILELOG_FILE scrapy_log.txt LOG_ENCODING utf-8这两行配置一加Scrapy 就会自动创建一个FileHandler把日志追加写入指定文件。注意是追加而不是覆盖所以如果你反复跑爬虫日志会越积越多。这一点后面讲日志切割时会重点说。LOG_ENCODING默认是utf-8一般不用改。但如果你在 Windows 上跑爬虫且日志里包含中文有时候会遇到乱码。这时候确认一下文件是否真的以 UTF-8 打开以及你的编辑器是不是用 UTF-8 解码。我遇到过一种情况日志文件本身是 UTF-8但用记事本打开显示乱码换成 VS Code 就正常了。这不是 Scrapy 的问题是编辑器的锅。还有一个坑LOG_FILE的路径如果是相对路径它是相对于你运行scrapy crawl命令时所在的目录而不是相对于settings.py所在的目录。很多人把settings.py放在项目里然后在项目根目录跑爬虫结果日志文件生成在了根目录而不是项目目录。要避免这个问题直接用绝对路径最稳妥。3.2 LOG_LEVEL 与 LOG_ENABLED 的优先级关系LOG_LEVEL控制日志的最低输出级别LOG_ENABLED控制日志的总开关。两者的关系是LOG_ENABLED False时LOG_LEVEL设成什么都不管用所有日志全部关闭LOG_ENABLED True时只有级别大于等于LOG_LEVEL的日志才会输出。这里有个实战技巧你可以在 Spider 内部动态调整日志级别。比如某个 Spider 在解析时遇到了预期外的页面结构你想临时打开 DEBUG 看看可以这样写import logging class MySpider(scrapy.Spider): name my_spider def parse(self, response): self.logger.setLevel(logging.DEBUG) self.logger.debug(f响应内容长度: {len(response.text)})self.logger是 Scrapy 为每个 Spider 实例自动创建的 logger名字就是 Spider 的 name。用这种方式调整级别只影响当前 Spider不会污染全局配置。3.3 关闭特定组件的日志噪音Scrapy 有些组件在 INFO 级别下也会输出大量日志最典型的就是scrapy.core.scraper和scrapy.extensions.logstats。如果你觉得这些日志太吵可以单独调高它们的级别import logging LOGGING { version: 1, disable_existing_loggers: False, loggers: { scrapy.core.scraper: { level: WARNING, }, scrapy.extensions.logstats: { level: WARNING, }, }, }注意这里的LOGGING字典是 Python 标准库logging.config.dictConfig的格式Scrapy 会读取它并覆盖默认配置。disable_existing_loggers一定要设为False否则会把 Scrapy 已经创建好的 logger 全部禁用导致日志完全消失。这个坑我踩过一次当时排查了半天才发现是这行配置写成了True。4. 把日志写进文件并实现按天切割的完整方案4.1 为什么 Scrapy 自带的 LOG_FILE 不够用LOG_FILE虽然方便但它有两个硬伤一是所有日志都堆在一个文件里时间长了文件会大到打不开二是没有自动清理机制磁盘空间会被慢慢吃掉。一个跑了三个月的爬虫日志文件上 GB 是常有的事。要解决这个问题就得引入TimedRotatingFileHandler或RotatingFileHandler。前者按时间切割后者按文件大小切割。对于爬虫场景我推荐按时间切割因为排查问题时通常关心某一天发生了什么按天切割最符合直觉。4.2 用 dictConfig 配置按天切割的日志下面是一套我用了很久的配置直接放在settings.py里就能生效import logging from logging.handlers import TimedRotatingFileHandler import os LOG_DIR os.path.join(os.path.dirname(os.path.abspath(__file__)), logs) if not os.path.exists(LOG_DIR): os.makedirs(LOG_DIR) LOGGING { version: 1, disable_existing_loggers: False, formatters: { standard: { format: %(asctime)s [%(name)s] %(levelname)s: %(message)s, datefmt: %Y-%m-%d %H:%M:%S, }, }, handlers: { file: { level: INFO, class: logging.handlers.TimedRotatingFileHandler, filename: os.path.join(LOG_DIR, spider.log), when: midnight, interval: 1, backupCount: 7, encoding: utf-8, formatter: standard, }, console: { level: INFO, class: logging.StreamHandler, formatter: standard, }, }, root: { handlers: [file, console], level: INFO, }, }这套配置做了几件事日志同时输出到文件和控制台文件每天午夜切割一次保留最近 7 天的备份日志目录不存在时自动创建。whenmidnight表示每天午夜切割interval1表示间隔 1 天backupCount7表示保留 7 个备份文件。切割后的文件名会带上日期后缀比如spider.log.2024-01-15。超过 7 天的文件会被自动删除不用担心磁盘被撑爆。4.3 切割后的文件命名与清理策略TimedRotatingFileHandler的命名规则是当前正在写的文件保持原名spider.log切割后的历史文件加上时间后缀。后缀的格式由when参数决定midnight对应的是%Y-%m-%d。这里有个细节切割发生在午夜但切割的那一刻日志会先写入旧文件还是新文件答案是午夜之后的第一条日志会触发切割旧文件被重命名新文件被创建。所以如果你在午夜前后查看日志可能会看到两个文件同时存在这是正常的。backupCount的清理逻辑是保留backupCount个历史文件加上当前文件一共backupCount 1个。如果你设成 7实际磁盘上最多有 8 个文件。这个细节在估算磁盘占用时要注意。4.4 多爬虫共用日志文件的冲突问题如果你有多个 Spider 同时跑且都往同一个日志文件写会出现两个问题一是日志交错难以区分哪条是哪个爬虫的二是TimedRotatingFileHandler在多进程下切割时可能出问题因为多个进程同时尝试重命名文件会冲突。解决办法有两个。方案一是每个 Spider 用独立的日志文件在 Spider 的custom_settings里覆盖LOG_FILEclass MySpider(scrapy.Spider): name my_spider custom_settings { LOG_FILE: flogs/{name}.log, }方案二是用scrapy.utils.log.configure_logging在启动时动态配置但这种方式比较绕不推荐新手用。我一般用方案一简单直接。5. 按级别分流日志与自定义 Logger 的正确姿势5.1 为什么要把 ERROR 和 INFO 分开写把所有日志写在一个文件里排查问题时得用grep过滤效率不高。更好的做法是按级别分流INFO 及以上的写一个文件ERROR 及以上的单独写一个文件。这样出问题时直接看 ERROR 文件一目了然。实现方式是在handlers里加一个专门处理 ERROR 的 handlerhandlers: { file_info: { level: INFO, class: logging.handlers.TimedRotatingFileHandler, filename: os.path.join(LOG_DIR, spider_info.log), when: midnight, backupCount: 7, encoding: utf-8, formatter: standard, }, file_error: { level: ERROR, class: logging.handlers.TimedRotatingFileHandler, filename: os.path.join(LOG_DIR, spider_error.log), when: midnight, backupCount: 30, encoding: utf-8, formatter: standard, }, }, root: { handlers: [file_info, file_error, console], level: INFO, },注意 ERROR 文件的backupCount我设成了 30因为错误日志通常量少但价值高保留久一点方便追溯。INFO 文件保留 7 天就够了毕竟量太大。5.2 在 Spider 和 Pipeline 里正确使用 self.loggerScrapy 为每个 Spider 和 Pipeline 都提供了self.logger直接用就行不要自己logging.getLogger(__name__)再创建一遍。原因在于 Scrapy 的 logger 已经绑定了组件名自己创建的 logger 名字可能不对导致日志格式里的%(name)s显示不出来。在 Spider 里class MySpider(scrapy.Spider): name my_spider def parse(self, response): self.logger.info(f正在解析: {response.url}) try: title response.css(h1::text).get() self.logger.debug(f提取到标题: {title}) except Exception as e: self.logger.error(f解析失败: {response.url}, 错误: {e})在 Pipeline 里class MyPipeline: def process_item(self, item, spider): spider.logger.info(f处理 Item: {item.get(title)}) return item注意 Pipeline 里用的是spider.logger而不是self.logger因为 Pipeline 实例本身没有绑定 logger得从 spider 参数拿。5.3 用 LogFormatter 给日志加上请求上下文Scrapy 提供了一个LogFormatter类可以在日志里自动带上请求的 URL、方法、状态码等信息。要启用它在settings.py里加LOG_FORMATTER scrapy.logformatter.LogFormatter启用后当你在下载中间件或 Spider 里记录日志时如果传了extra参数包含request或response日志会自动格式化。比如self.logger.info(处理响应, extra{response: response})输出会变成类似Crawled (200) GET https://example.com的格式。这个功能在排查哪个请求出了问题时特别有用省得你手动拼 URL。6. 那些年我在 Scrapy 日志上踩过的坑6.1 日志文件把磁盘写满的真实案例有一次我写了个爬虫跑在一台小内存的服务器上日志级别设的 DEBUGLOG_FILE指向了一个没有切割的固定文件。爬虫跑了三天第四天服务器报警磁盘满了。登上去一看日志文件 12GB直接把根分区撑爆了。这个坑的教训是生产环境的爬虫日志必须切割且必须设置保留上限。DEBUG 级别只在调试时开上线前一定要改回 INFO 或 WARNING。另外如果服务器磁盘本身就不大可以考虑把日志写到单独的挂载点或者用RotatingFileHandler按大小切割比如每 100MB 切一个文件保留 10 个。6.2 日志重复输出两遍的排查过程有段时间我发现日志里每条记录都出现两次一模一样。排查了半天最后发现是settings.py里同时配了LOG_FILE和LOGGING字典。Scrapy 会先根据LOG_FILE创建一个 handler然后LOGGING字典又创建了一个 handler两个 handler 都往同一个文件写自然就重复了。解决办法很简单要么用LOG_FILE要么用LOGGING不要两个一起用。我现在的习惯是统一用LOGGING因为它的控制粒度更细能配置切割、分流、格式等。6.3 中文日志乱码的三种成因中文乱码这个问题我遇到过至少三种情况。第一种是LOG_ENCODING没设成utf-8这个改配置就行。第二种是日志文件本身是 UTF-8但用 Windows 记事本打开记事本默认用 GBK 解码显示乱码。这个换编辑器就好。第三种最隐蔽日志里混入了从网页抓取的内容而网页本身的编码不是 UTF-8比如 GBK 或 GB2312写入日志时没做转换导致文件里混了两种编码。第三种情况的解决办法是在记录日志前统一转码text response.text if isinstance(text, bytes): text text.decode(utf-8, errorsignore) self.logger.info(f内容: {text})用errorsignore可以避免因为个别非法字符导致整个日志记录失败。6.4 日志级别设错导致关键错误被吞掉有一次线上爬虫跑了一周数据量突然掉了一半但日志里一条 ERROR 都没有。查了半天才发现LOG_LEVEL被设成了CRITICAL而实际发生的错误都是ERROR级别全被过滤掉了。这个坑的教训是日志级别不要设得比 ERROR 还高除非你确定不需要任何错误信息。生产环境最低也要保持WARNING最好用INFO。7. 让日志真正服务于排查几个实战习惯配好日志只是第一步怎么用日志才是关键。我养成了几个习惯分享出来供参考。第一个习惯是在关键节点打日志。比如 Spider 启动时记录目标 URL 列表的长度每次解析成功时记录 Item 数量Pipeline 写入数据库时记录批次大小。这些日志在正常运行时看起来没用但一旦数据量异常你能快速定位是哪个环节出了问题。第二个习惯是给日志加唯一标识。如果一次爬取涉及多个页面可以在日志里带上请求的 URL 或 Item 的 ID这样用grep一搜就能把同一条数据的完整链路串起来。第三个习惯是定期检查 ERROR 日志。我每周会花十分钟看看 ERROR 文件很多时候能发现一些被忽略的小问题比如某个字段偶尔解析失败、某个页面偶尔超时。这些问题在数据量小的时候不明显但积累起来会影响数据质量。第四个习惯是日志和监控结合。如果爬虫跑在服务器上可以用tail -f实时看日志或者把 ERROR 日志接入告警系统一旦出现就发通知。这样不用一直盯着屏幕出问题能第一时间知道。日志这个东西配的时候嫌麻烦用的时候真香。尤其是当爬虫在半夜跑挂了你却不知道为什么的时候一份清晰的日志就是救命稻草。花半小时把日志配好能省下后面无数小时的排查时间这笔账怎么算都划算。