拓冰网站定制 
干爬虫这些年我接手过的项目少说也有十几个其中九个的日志系统都是能跑就行的状态。直到有一次凌晨两点线上爬虫突然停摆解析规则没问题、数据库连接正常、代理池也没挂我硬是排查了三个小时才找到真凶——日志文件把磁盘写满了进程直接被系统干掉。从那之后我养成了一个习惯接到新项目第一件事就是把Scrapy日志系统和生产环境配置从头到尾梳理一遍。这篇博文就把我积累的这些东西完整写出来包括日志系统的工作原理、settings里的各种开关、扩展机制、生产环境落地配置还有我踩过的坑。不管你是刚把本地爬虫脚本改成生产任务还是被日志问题搞得焦头烂额这篇内容应该能帮你节省不少排查时间。1. 先从一次线上事故说起日志系统为什么值得认真对待1.1 那个把磁盘写满的日志文件那次事故的具体情况是这样的项目大概每天爬取30万条商品数据跑了一个多月没出过问题。某个凌晨我的告警电话响了说爬虫进程消失了systemd把它标记为failed。我登录服务器一看磁盘使用率100%df -h显示/目录已经被占满再一看罪魁祸首是logs/scrapy.log大小已经是18GB了。为什么会这样因为当时图省事直接在settings.py里配置了LOG_FILE logs/scrapy.log这是Scrapy官方提供的最简单的文件日志方案。但这个方案的本质就是用一个FileHandler往同一个文件里追加写入既不切割、不压缩、也不清理旧文件。一个每天写入几百MB的爬虫项目跑一个月就是这个结果。这里需要特别说明一个新手容易忽略的点Scrapy默认是只在控制台输出日志的你配置了LOG_FILE之后控制台就没了全部写进文件。但Scrapy不会帮你做任何轮转log rotation。这不是Scrapy的疏漏因为日志轮转这件事本身就是部署层该负责的但在实际项目中大多数人不会单独给爬虫配一个logrotate任务于是日志就成了定时炸弹。后面第4章我会给出完整的解决方案。1.2 Scrapy日志系统的基本工作原理要避开这些坑先得搞清楚Scrapy日志系统到底是怎么运转的。简单说Scrapy的日志建立在Python标准库logging之上没有自己另搞一套。它内部维护了一组以scrapy开头的logger实例比如scrapy.core.engine、scrapy.core.scraper、scrapy.core.downloader、scrapy.middleware、scrapy.extensions.logstats等等。爬虫在运行过程中引擎、下载器、中间件、扩展这些组件都会往对应的logger里写日志事件。这些日志事件本身只是一条条带级别和上下文的消息真正决定它们去哪里的是root logger上的handler。Scrapy启动时会调用configure_logging()做一次统一配置如果你设置了LOG_FILE就往root logger加一个FileHandler如果没有就加一个StreamHandler输出到控制台。第三方库比如requests、selenium、playwright打出来的日志只要是通过标准logging产生的也会被root logger一起捕获。很多人在这个环节困惑的点是为什么我设置了LOG_FILE之后控制台什么都没有了因为默认的配置逻辑就是文件或控制台二选一——设置了LOG_FILE就只写文件。要让两者同时输出就得自己配多个handler。这一点我在第4章的统一方案里会解决。理解了日志的三个关键角色logger谁产生消息、handler消息去哪里、formatter消息长什么样子后面所有配置你都能自己推出来。Scrapy给的settings项本质上都是对这些角色的操作LOG_LEVEL控制logger的过滤级别LOG_FILE决定handler是文件还是屏幕LOG_FORMAT和LOG_DATEFORMAT控制formatter的模板。搞懂这层对应关系你就不会被各种配置项绕晕了。2. settings.py 里的日志开关最常用的配置方式2.1 核心配置项逐一拆解Scrapy的日志配置绝大部分都在settings.py里完成下面这几个是必须掌握的。LOG_ENABLED默认True。这个开关控制是否启用日志系统我建议永远别关。有些人为了让爬虫跑得快一点会把它关掉一旦出问题连排查依据都没有得不偿失。LOG_LEVEL默认DEBUG。在生产环境我强烈建议改成INFO。别小看这个改动DEBUG级别的日志量通常是INFO的好几倍具体来说scrapy.core.engine在DEBUG级别下几乎每个请求的进出都会打两条日志高并发爬虫一天能多写几个GB。LOG_FILE默认None。不设置就是输出到控制台设置了就写入文件。注意一点这个配置本身不做切割和LOG_LEVEL配合使用进生产环境前一定要先解决轮转问题。LOG_FILE_MODE默认wb。这个很多人没注意到它控制文件的写入模式wb会覆盖旧文件。也就是说每次启动爬虫同名日志文件会被清空重写。如果你想保留历史日志需要改成ab追加模式。但更推荐的做法还是用第4章的滚动handler。LOG_FORMAT默认字符串是%(asctime)s [%(name)s] %(levelname)s: %(message)s。这里可用的是Python logging标准字段比如%(filename)s、%(lineno)d需要时自己拼。LOG_DATEFORMAT默认%Y-%m-%d %H:%M:%S。按自己喜好调整我习惯加上毫秒%Y-%m-%d %H:%M:%S,%f排查对比两个事件的先后顺序时很有用。LOG_SHORT_NAMES默认False。如果设为True日志里的[scrapy.core.engine]会被简写成[engine]。我建议保持False生产环境日志就是要信息全多几个字符不算什么。LOG_STDOUT默认False。如果设为TruePython的print输出也会被重定向到日志系统里。这个选项适合那种代码里残留了很多print的老项目临时救急很好用但新代码还是老老实实用logger。下面用一个表格把这些汇总配置项默认值生产环境建议说明LOG_ENABLEDTrueTrue总开关LOG_LEVELDEBUGINFO控制日志量LOG_FILENone配合轮转使用文件输出LOG_FILE_MODEwbab覆盖或追加LOG_FORMAT标准模板建议加时间毫秒日志格式LOG_DATEFORMAT日期默认建议加毫秒时间格式LOG_SHORT_NAMESFalseFalse保留完整logger名LOG_STDOUTFalse看需求print重定向2.2 命令行和代码里的覆盖配置配置日志不一定非要写在settings.py里Scrapy支持多种覆盖方式优先级是命令行参数 settings.py 代码默认值。命令行方面scrapy crawl myspider -L WARNING可以直接覆盖日志级别scrapy crawl myspider -s LOG_FILExxx.log可以动态指定日志文件。这个主要用于临时排查问题比如线上日志量太大不想全量记录可以先用-L WARNING看一下有没有错误堆栈。代码层面如果要在一个脚本里用CrawlerProcess跑多个爬虫并分别控制日志可以通过get_project_settings()拿到settings对象后修改它的值再传给CrawlerProcess。注意修改必须发生在CrawlerProcess实例化之前。如果是用CrawlerRunner在Twisted reactor里跑多个爬虫同理必须在create_crawler之前改。我见过一些项目会在一个进程里连续跑多个爬虫然后发现第二个爬虫的日志级别不对就是因为settings对象在第一个爬虫启动时被改了没有给第二个爬虫恢复。这种场景建议不要再改全局settings而是每个爬虫在自己的custom_settings里定义日志配置Scrapy会在创建该爬虫实例时合并这些配置。2.3 日志级别选择的实战建议一条经验法则开发用DEBUG预发布用INFO核心链路用WARNING兜底。生产环境全量开DEBUG通常是不必要的。我们算一笔账假设一个爬虫每秒处理50个请求DEBUG级别下引擎日志和下载器日志加起来每个请求大概3~4条每秒就是200条日志。如果每条平均100字节一天就是1.7GB。而INFO级别下同样的爬虫一天的日志量通常在200MB以内。差距是数量级的。但也不能只看数量。生产环境如果完全不开INFO很多关键信息会丢失。比如spider_opened和spider_closed是INFO级别item_scraped如果是通过LogStats输出的也是INFO级别这些是你判断爬虫是否健康的核心依据。所以我的建议是生产环境默认INFO频繁出错的环节单独用logger.warning或logger.error输出既控制量又不丢关键信息。3. 理解Scrapy的扩展机制日志系统背后的推手3.1 Scrapy扩展是什么为什么日志要依赖扩展很多人在热词里搜scrapy中extensions是什么其实就是没搞懂Scrapy里那套插件机制。Scrapy扩展Extension本质上是普通的Python类通过from_crawler类方法获得crawler实例然后借助crawler.signals.connect订阅爬虫生命周期中的各种信号比如spider_opened、spider_closed、item_scraped、response_received等在这些事件发生时执行自己的逻辑。日志和统计数据强相关而Scrapy的统计数据Stats Collector本身就是一个跨组件的状态容器所以日志功能天然适合用扩展来实现。最典型的例子是Scrapy内置的LogStats扩展它会在爬虫运行期间每隔一段时间输出一条类似这样的日志2024-06-18 10:30:00 [scrapy.extensions.logstats] INFO: Crawled 1200 pages (at 4 pages/min), scraped 850 items (at 3 items/min)这条日志不是引擎自动打的就是LogStats这个扩展在收到定时信号后从Stats Collector里取出数据通过logger输出的一条INFO消息。理解这一点你在解决日志不输出的问题时就会多一个排查方向是不是自定义扩展或默认扩展被禁用了Scrapy里有EXTENSIONS_BASE这个默认扩展集合里面包含了LogStats、CoreStats、Debugger等。你自己添加扩展可以通过EXTENSIONS配置项而禁用默认扩展也可以在这个配置里显式设为None。3.2 手写一个日志统计扩展按站点和状态码输出理解了机制我们就直接实操。下面这个扩展解决的问题很典型大型爬虫往往要跑多个站点你会非常需要知道每个站点的响应状态码分布、Item产出速率。Scrapy标准LogStats只给总量不给细分维度所以我们自己写一个扩展。import logging from collections import Counter, defaultdict from scrapy import signals logger logging.getLogger(crawler.site_health) class SiteStatsLogExtension: def __init__(self, crawler, log_every500): self.crawler crawler self.stats crawler.stats self.log_every log_every self.response_counter Counter() self.item_counter defaultdict(int) self.total_count 0 classmethod def from_crawler(cls, crawler): ext cls(crawler, crawler.settings.getint(SITE_STATS_LOG_EVERY, 500)) crawler.signals.connect(ext.spider_opened, signals.spider_opened) crawler.signals.connect(ext.response_received, signals.response_received) crawler.signals.connect(ext.item_scraped, signals.item_scraped) crawler.signals.connect(ext.spider_closed, signals.spider_closed) return ext def spider_opened(self, spider): logger.info(site stats module started, log every %d events, self.log_every) def response_received(self, response, **kwargs): site getattr(response, site_name, None) or response.url.split(/)[2] self.response_counter[(site, response.status)] 1 self.total_count 1 if self.total_count % self.log_every 0: self._emit_current_stats(spider_hint) def item_scraped(self, item, spider, **kwargs): site getattr(spider, site_name, None) or spider.name self.item_counter[site] 1 def _emit_current_stats(self, spider_hint): resp_summary { f{site}:{status}: cnt for (site, status), cnt in self.response_counter.items() } item_summary dict(self.item_counter) logger.info( site health snapshot responses%s items%s, resp_summary, item_summary, ) def spider_closed(self, spider, reason): self._emit_current_stats(spider_hintspider.name) logger.info(site stats module closed, total events %d, self.total_count)然后在settings.py里注册这个扩展EXTENSIONS { myproject.extensions.SiteStatsLogExtension: 500, }数字500表示优先级数字越小越早执行。这样在爬虫跑起来后每处理500个响应就会输出一条包含状态码分布和item数量的JSON风格日志配合第4章的结构化输出可以直接拿去喂给日志平台做告警。注意事项有两个。第一response_received信号携带的response在中间件里不一定有site_name属性所以我在代码里做了兜底——取URL的域名。这在实际运行中很关键不然扩展刚上线就会因为AttributeError导致整个爬虫挂掉。第二扩展里的异常处理不能省略如果_emit_current_stats内部出问题也不能让它影响主流程可以在方法体外面套一层try/except生产环境的扩展代码必须默认日志系统不能拖垮爬虫主线。4. 生产环境日志配置结构化、滚动与集中采集4.1 文件无限增长的坑滚动策略与handler替换回到第一章那个事故上根治办法就是给日志加滚动。但Scrapy的LOG_FILE配置项只创建FileHandler并不提供滚动能力所以需要自定义handler。这里有一个关键的实现前提Scrapy的configure_logging()会在crawler创建时运行如果你只是在settings.py顶层直接往root logger加handler很可能被它清掉。我踩过这个坑最后采用的稳妥方案是写一个扩展监听engine_started信号在日志系统初始化完成后替换root logger的handlers。import logging import os from logging.handlers import TimedRotatingFileHandler from scrapy import signals class LogRotationExtension: def __init__(self, log_dir, backup_days): self.log_dir log_dir self.backup_days backup_days classmethod def from_crawler(cls, crawler): ext cls( log_dircrawler.settings.get(LOG_DIR, logs), backup_dayscrawler.settings.getint(LOG_BACKUP_DAYS, 7), ) crawler.signals.connect(ext.engine_started, signals.engine_started) return ext def engine_started(self): root logging.getLogger() # 移除Scrapy默认添加的handler避免重复输出 for handler in root.handlers[:]: root.removeHandler(handler) os.makedirs(self.log_dir, exist_okTrue) formatter logging.Formatter( %(asctime)s [%(name)s] %(levelname)s: %(message)s, datefmt%Y-%m-%d %H:%M:%S,%f, ) file_handler TimedRotatingFileHandler( os.path.join(self.log_dir, scrapy.log), whenmidnight, backupCountself.backup_days, encodingutf-8, ) file_handler.setFormatter(formatter) root.addHandler(file_handler) console_handler logging.StreamHandler() console_handler.setFormatter(formatter) root.addHandler(console_handler)TimedRotatingFileHandler的whenmidnight表示每天零点切割backupCount7保留最近7个日志文件自动删除更早的。如果一台机器上日志写入量很大也可以改用RotatingFileHandler按文件大小切割比如单文件超过500MB切一个。这两种方案都能解决磁盘被写满的问题。替换handler时注意root.handlers[:]的切片复制是为了边遍历边删除直接遍历原列表会出问题。另外因为扩展的from_crawler在日志配置之后执行engine_started在爬虫引擎启动时才触发所以这个替换是安全的不会与Scrapy默认handler的初始化逻辑产生竞态冲突。4.2 结构化日志输出让每一条日志都能被程序解析生产环境的日志不应该只是给人看的还要能被采集、检索、统计。最强的做法是把日志输出成JSON格式。这样后续接入ELK或Loki时不需要写一堆grok解析规则直接按字段查就行。实现方式是用自定义Formatter。下面是我项目里在用的一个轻量实现不依赖第三方库import json import logging class JsonFormatter(logging.Formatter): def format(self, record): data { timestamp: self.formatTime(record, self.datefmt), logger: record.name, level: record.levelname, message: record.getMessage(), } if record.exc_info: data[exc_info] self.formatException(record.exc_info) return json.dumps(data, ensure_asciiFalse)然后在上一节的扩展里把file_handler.setFormatter(JsonFormatter())替换掉普通Formatter。控制台仍然可以用人类可读的Formatter文件用JSON这样兼顾排查和机器采集。这里有一个细节message里如果包含对象json.dumps会被类型卡住。我在生产里只允许字符串、数字、字典和列表有一个简单的兜底办法对message做str()强制转换但这样嵌套结构就不好看了。更干净的做法是在写入日志时统一用logger.info(xxx, extra{payload: {...}})然后在Formatter里拼装。总之日志平台字段越多后续监控告警越灵活。ensure_asciiFalse必须加上不然中文全变成\u转义序列看起来非常痛苦。这是一行必须记住的代码。4.3 敏感信息脱敏与记录边界爬虫日志经常会把URL、Cookie、Token、请求参数一起打出来这在本地没问题但生产环境的日志往往会被采集到统一的日志平台这就有信息泄露风险。我在日志系统中做了两层防护。第一层在可能涉及敏感信息的日志位置不打印完整内容。比如请求头里的Cookie就用logger.debug(cookie: ***)或者只打前几个字符。但代码是很多人写的靠自觉不可靠。第二层更稳妥的办法是加Filter。Filter可以在日志事件到达handler之前修改或丢弃消息。下面这个Filter会把常见敏感字段的值替换成掩码import re class SensitiveDataFilter(logging.Filter): def __init__(self, patternsNone): super().__init__() self.patterns patterns or [ (r(cookie[:]\s*)[^;\s], r\1***), (r(token[:]\s*)[^\s], r\1***), (r(password[:]\s*)[^\s], r\1***), ] def filter(self, record): msg record.getMessage() for pattern, repl in self.patterns: msg re.sub(pattern, repl, msg, flagsre.IGNORECASE) record.msg msg record.args () return True这个Filter要添加到所有输出到外部的handler上而不是只加在root logger上。如果你只加在一个handler上控制台能看到原始信息、日志平台只能看到脱敏信息这在某些场景下是有意为之的但要注意统一不然排查问题时会对着脱敏后的日志干瞪眼。4.4 日志分析工具选型日志采集和分析是生产环境绕不开的一环。如果项目规模不大单机几台服务器我推荐轻量方案Filebeat Loki Grafana。Filebeat负责读日志文件Loki负责存储和索引Grafana做可视化。这套方案比ELK轻得多对内存的占用只有ELK的几分之一尤其适合小团队自己维护。如果公司已经有ELKElasticsearch Logstash Kibana那就直接接入Filebeat把日志推到Logstash或者用Elastic Agent直接发到ES。因为日志已经是JSON结构化不需要再在Logstash里写grok解析整个链路会很流畅。关于AI工具精准分析日志我的态度是AI适合做辅助排查、发现异常模式、解释报错堆栈但前提是日志必须结构和采集做得好。如果日志是一堆无规则的文本任何AI工具也很难榨出有效信息。所以第一步永远是先把日志结构化和集中化然后再考虑让AI帮你从海量日志里找线索。我自己用下来觉得AI在给出一段报错、让它猜测可能原因这个场景效率很高但在实时监控告警上还是规则和指标更可靠。5. 生产环境实操一个可直接落地的完整配置5.1 完整配置包settings、扩展、启动命令把前面几章的东西串起来我现在给出一个可以直接抄的配置包。项目的目录结构大致是这样myproject/ ├── scrapy.cfg ├── myproject/ │ ├── settings.py │ ├── extensions/ │ │ ├── __init__.py │ │ ├── log_rotation.py │ │ └── site_stats.py │ └── spiders/settings.py里这样写LOG_ENABLED True LOG_LEVEL INFO LOG_FILE_MODE ab LOG_ENCODING utf-8 LOG_SHORT_NAMES False # 自定义日志扩展 EXTENSIONS { myproject.extensions.log_rotation.LogRotationExtension: 100, myproject.extensions.site_stats.SiteStatsLogExtension: 500, } # 扩展用到的自定义配置 LOG_DIR logs LOG_BACKUP_DAYS 7 SITE_STATS_LOG_EVERY 500这里的优先级数字要注意LogRotationExtension的优先级是100SiteStatsLogExtension是500数字小先执行。滚动日志的初始化在engine_started时执行而SiteStats在spider_opened时才开始统计两者不会冲突。如果你还用了playwright抓动态页面尤其是带iframe的复杂页面记住一个经验给每次iframe上下文切换和页面加载的关键节点打上spider.info级别的日志但别在请求循环里打印完整DOM。我处理过一个案例爬虫在抓某个嵌套三层iframe的页面时偶尔超时就是靠日志里记录的iframe加载状态才确认是某个广告iframe一直在刷接口导致的这种问题靠肉眼是看不出来的。5.2 验证与性能压测日志系统的瓶颈在哪里配置完之后不要直接上生产先做两件验证日志是否按预期切分以及日志IO对爬虫吞吐的影响。切分验证很简单手动改系统时间或者触发一次midnight切割比较麻烦可以用whenS和interval3600临时跑一小时验证或者干脆把when设成H每小时一切在生产上也够用我更喜欢按小时切割便于按小时粒度去回溯问题。验证输出观察logs/scrapy.log.2024-06-18这类带日期的归档文件是否生成以及scrapy.log本身是否被清空重建。性能方面我的实测经验是单进程500QPS以内同步FileHandler没有任何压力超过1000QPS日志写入会开始拖累主流程尤其是每个请求打多条DEBUG时更明显。解决方案有两个方向一是降低日志级别、减少日志事件数量二是用异步handler比如QueueHandler配合后台线程消费。简单可用的异步方案代码import logging import queue from logging.handlers import QueueHandler, QueueListener log_queue queue.Queue(-1) queue_handler QueueHandler(log_queue) queue_listener QueueListener( queue_handler, file_handler, console_handler, respect_handler_levelTrue, ) queue_listener.start()把queue_listener.start()放在扩展的engine_started里然后把queue_handler作为root logger的唯一handler。这样主线程把日志事件丢进队列就立刻返回真正写文件的IO在后台线程做。压测下来在1200QPS的场景下异步方案让爬虫吞吐几乎没有下降。但这个方案的代价是进程退出时可能丢日志所以要在爬虫关闭时调用queue_listener.stop()确保队列消费完。这里就不展开完整生命周期管理了生产使用务必在spider_closed或close_spider里处理。5.3 监控告警日志不只是用来事后排查日志的最高级用法是变成实时监控信号。我习惯在项目里实现一个爬虫心跳日志每隔固定时间如果爬虫还在正常产出item就输出一条心跳日志如果连续多个心跳周期没有产出监控平台就会告警。实现思路还是依赖Stats Collector。在上一节的SiteStats扩展基础上增加一个计时逻辑import time class HeartbeatMixin: def __init__(self, crawler, heartbeat_interval300): self.crawler crawler self.heartbeat_interval heartbeat_interval self.last_item_time time.time() def item_scraped(self, item, spider, **kwargs): self.last_item_time time.time() # 原有统计逻辑... def _check_heartbeat(self, spider): idle_seconds time.time() - self.last_item_time if idle_seconds self.heartbeat_interval: logger.warning( heartbeat missing: spider%s idle_seconds%s, spider.name, idle_seconds, )然后在settings里用extension连接一个定时信号或者更简单地在item_scraped里检查时间差。因为爬虫总是在处理item所以这个检查不需要额外定时器。如果爬虫卡死item_scraped本身就不会触发但heartbeat missing日志也会消失所以需要外部监控配合——监控平台如果没有在5分钟内收到该爬虫的任何日志就触发告警。这套逻辑我在多个项目里都用属于投资小、回报高的一类监控。另一类告警是基于错误率。我会让扩展维护一个错误状态码统计比如在一个窗口内5xx比例超过20%就通过logger.error输出一条特定前缀的告警日志由监控平台直接截获转发。这样做的好处是业务告警逻辑完全收敛在爬虫项目里运维侧只需要配置一条匹配规则。6. 常见问题排查实录8个真实Case速查日志系统出问题翻文档往往没用因为网上都是照抄配置不讲为什么。下面这8个Case是我这几年实际遇到过的整理成速查表。现象直接原因解决办法设置了LOG_FILE但文件是空的LOG_ENABLED被改成False检查settings和启动参数控制台突然没有日志设置了LOG_FILE后默认只写文件按第4章方式自定义双handler日志隔一段时间翻倍增长自定义扩展重复添加handler先remove再add做幂等处理磁盘被日志撑爆使用了LOG_FILE没有轮转用TimedRotatingFileHandler日志中文乱码FileHandler默认编码不对LOG_ENCODINGutf-8 或创建handler时指定日志级别改了不生效命令行-L参数优先级更高检查crawl命令完整参数某些中间件的日志看不到该中间件用的是第三方logger确认root logger级别必要时单独设level爬虫崩了但日志里没有堆栈异常发生在信号回调里被吞掉在扩展和信号处理里增加try/except并logger.exception逐条展开说一些宝贵经验。第一个设置LOG_FILE后文件为空我排查过好几次最后发现是settings.py里某个环境判断逻辑在这个环境下把LOG_ENABLED设成了False。不要觉得这个配置没人动生产环境经常有多套配置互相覆盖。第二个控制台没日志很多人以为是代码问题其实是Scrapy文件或控制台二选一的默认逻辑。如果你既想保留控制台输出又想写文件就别用LOG_FILE改用自定义handler。第三个日志翻倍增长。这个最有隐蔽性因为不是报错只是日志从某次上线后突然暴增。最后查到是一个监控扩展重复执行了root.addHandler每注册一次就多一个handler同一条日志被写N遍。解决办法是在addHandler之前先遍历移除同类handler或者维护一个标志变量。第四个磁盘被日志撑爆就是第一章的场景。不重复了。第五个中文乱码。Scrapy的LOG_FILE用的是系统默认编码在有些服务器上是ASCII中文直接变成问号或抛异常。设置LOG_ENCODING utf-8即可。自定义handler时记得在FileHandler(..., encodingutf-8)里显式指定。第六个日志级别不生效。有一回我一个爬虫里设置custom_settings {LOG_LEVEL: DEBUG}但跑起来还是INFO。原因是我在命令行用了-L INFO命令行优先级高于custom_settings。所以要检查完整启动命令别只盯着代码。第七个第三方库日志丢失。常见的比如selenium的webdriver_manager日志、requests的urllib3日志。Scrapy的root logger默认会捕获它们但有些库创建了独立的logger并设置了propagate False导致日志不会冒泡到root。处理办法是显式设置该logger的级别和handler比如logging.getLogger(urllib3).setLevel(logging.WARNING)。第八个爬虫崩了但没堆栈。这个坑在自定义信号回调里最典型。信号回调如果抛出异常经常会被Twisted的日志系统捕获并打到一个独立的logger里如果不仔细看你只会看到spider关闭不知道异常在哪。我在所有扩展的公共方法里都加了兜底def _safe_log(self, func, *args, **kwargs): try: func(*args, **kwargs) except Exception: logger.exception(extension method failed: %s, func.__name__)日志系统本身的故障不能影响爬虫主流程这是生产环境的底线。最后再分享一个小技巧。排查日志问题时我通常会先在本地用scrapy crawl myspider -L DEBUG -s LOG_ENABLEDTrue跑一小段把全部日志落到一个临时文件里然后对比生产环境的差异。这比直接改生产配置快很多。生产环境配置日志是个慢功夫一次配好、持续观察、逐步优化比出问题再救火舒服太多了。希望这篇内容能让你在配置Scrapy日志时少踩几个坑。 Scrapy日志系统生产环境配置指南：从原理到落地
干爬虫这些年我接手过的项目少说也有十几个其中九个的日志系统都是能跑就行的状态。直到有一次凌晨两点线上爬虫突然停摆解析规则没问题、数据库连接正常、代理池也没挂我硬是排查了三个小时才找到真凶——日志文件把磁盘写满了进程直接被系统干掉。从那之后我养成了一个习惯接到新项目第一件事就是把Scrapy日志系统和生产环境配置从头到尾梳理一遍。这篇博文就把我积累的这些东西完整写出来包括日志系统的工作原理、settings里的各种开关、扩展机制、生产环境落地配置还有我踩过的坑。不管你是刚把本地爬虫脚本改成生产任务还是被日志问题搞得焦头烂额这篇内容应该能帮你节省不少排查时间。1. 先从一次线上事故说起日志系统为什么值得认真对待1.1 那个把磁盘写满的日志文件那次事故的具体情况是这样的项目大概每天爬取30万条商品数据跑了一个多月没出过问题。某个凌晨我的告警电话响了说爬虫进程消失了systemd把它标记为failed。我登录服务器一看磁盘使用率100%df -h显示/目录已经被占满再一看罪魁祸首是logs/scrapy.log大小已经是18GB了。为什么会这样因为当时图省事直接在settings.py里配置了LOG_FILE logs/scrapy.log这是Scrapy官方提供的最简单的文件日志方案。但这个方案的本质就是用一个FileHandler往同一个文件里追加写入既不切割、不压缩、也不清理旧文件。一个每天写入几百MB的爬虫项目跑一个月就是这个结果。这里需要特别说明一个新手容易忽略的点Scrapy默认是只在控制台输出日志的你配置了LOG_FILE之后控制台就没了全部写进文件。但Scrapy不会帮你做任何轮转log rotation。这不是Scrapy的疏漏因为日志轮转这件事本身就是部署层该负责的但在实际项目中大多数人不会单独给爬虫配一个logrotate任务于是日志就成了定时炸弹。后面第4章我会给出完整的解决方案。1.2 Scrapy日志系统的基本工作原理要避开这些坑先得搞清楚Scrapy日志系统到底是怎么运转的。简单说Scrapy的日志建立在Python标准库logging之上没有自己另搞一套。它内部维护了一组以scrapy开头的logger实例比如scrapy.core.engine、scrapy.core.scraper、scrapy.core.downloader、scrapy.middleware、scrapy.extensions.logstats等等。爬虫在运行过程中引擎、下载器、中间件、扩展这些组件都会往对应的logger里写日志事件。这些日志事件本身只是一条条带级别和上下文的消息真正决定它们去哪里的是root logger上的handler。Scrapy启动时会调用configure_logging()做一次统一配置如果你设置了LOG_FILE就往root logger加一个FileHandler如果没有就加一个StreamHandler输出到控制台。第三方库比如requests、selenium、playwright打出来的日志只要是通过标准logging产生的也会被root logger一起捕获。很多人在这个环节困惑的点是为什么我设置了LOG_FILE之后控制台什么都没有了因为默认的配置逻辑就是文件或控制台二选一——设置了LOG_FILE就只写文件。要让两者同时输出就得自己配多个handler。这一点我在第4章的统一方案里会解决。理解了日志的三个关键角色logger谁产生消息、handler消息去哪里、formatter消息长什么样子后面所有配置你都能自己推出来。Scrapy给的settings项本质上都是对这些角色的操作LOG_LEVEL控制logger的过滤级别LOG_FILE决定handler是文件还是屏幕LOG_FORMAT和LOG_DATEFORMAT控制formatter的模板。搞懂这层对应关系你就不会被各种配置项绕晕了。2. settings.py 里的日志开关最常用的配置方式2.1 核心配置项逐一拆解Scrapy的日志配置绝大部分都在settings.py里完成下面这几个是必须掌握的。LOG_ENABLED默认True。这个开关控制是否启用日志系统我建议永远别关。有些人为了让爬虫跑得快一点会把它关掉一旦出问题连排查依据都没有得不偿失。LOG_LEVEL默认DEBUG。在生产环境我强烈建议改成INFO。别小看这个改动DEBUG级别的日志量通常是INFO的好几倍具体来说scrapy.core.engine在DEBUG级别下几乎每个请求的进出都会打两条日志高并发爬虫一天能多写几个GB。LOG_FILE默认None。不设置就是输出到控制台设置了就写入文件。注意一点这个配置本身不做切割和LOG_LEVEL配合使用进生产环境前一定要先解决轮转问题。LOG_FILE_MODE默认wb。这个很多人没注意到它控制文件的写入模式wb会覆盖旧文件。也就是说每次启动爬虫同名日志文件会被清空重写。如果你想保留历史日志需要改成ab追加模式。但更推荐的做法还是用第4章的滚动handler。LOG_FORMAT默认字符串是%(asctime)s [%(name)s] %(levelname)s: %(message)s。这里可用的是Python logging标准字段比如%(filename)s、%(lineno)d需要时自己拼。LOG_DATEFORMAT默认%Y-%m-%d %H:%M:%S。按自己喜好调整我习惯加上毫秒%Y-%m-%d %H:%M:%S,%f排查对比两个事件的先后顺序时很有用。LOG_SHORT_NAMES默认False。如果设为True日志里的[scrapy.core.engine]会被简写成[engine]。我建议保持False生产环境日志就是要信息全多几个字符不算什么。LOG_STDOUT默认False。如果设为TruePython的print输出也会被重定向到日志系统里。这个选项适合那种代码里残留了很多print的老项目临时救急很好用但新代码还是老老实实用logger。下面用一个表格把这些汇总配置项默认值生产环境建议说明LOG_ENABLEDTrueTrue总开关LOG_LEVELDEBUGINFO控制日志量LOG_FILENone配合轮转使用文件输出LOG_FILE_MODEwbab覆盖或追加LOG_FORMAT标准模板建议加时间毫秒日志格式LOG_DATEFORMAT日期默认建议加毫秒时间格式LOG_SHORT_NAMESFalseFalse保留完整logger名LOG_STDOUTFalse看需求print重定向2.2 命令行和代码里的覆盖配置配置日志不一定非要写在settings.py里Scrapy支持多种覆盖方式优先级是命令行参数 settings.py 代码默认值。命令行方面scrapy crawl myspider -L WARNING可以直接覆盖日志级别scrapy crawl myspider -s LOG_FILExxx.log可以动态指定日志文件。这个主要用于临时排查问题比如线上日志量太大不想全量记录可以先用-L WARNING看一下有没有错误堆栈。代码层面如果要在一个脚本里用CrawlerProcess跑多个爬虫并分别控制日志可以通过get_project_settings()拿到settings对象后修改它的值再传给CrawlerProcess。注意修改必须发生在CrawlerProcess实例化之前。如果是用CrawlerRunner在Twisted reactor里跑多个爬虫同理必须在create_crawler之前改。我见过一些项目会在一个进程里连续跑多个爬虫然后发现第二个爬虫的日志级别不对就是因为settings对象在第一个爬虫启动时被改了没有给第二个爬虫恢复。这种场景建议不要再改全局settings而是每个爬虫在自己的custom_settings里定义日志配置Scrapy会在创建该爬虫实例时合并这些配置。2.3 日志级别选择的实战建议一条经验法则开发用DEBUG预发布用INFO核心链路用WARNING兜底。生产环境全量开DEBUG通常是不必要的。我们算一笔账假设一个爬虫每秒处理50个请求DEBUG级别下引擎日志和下载器日志加起来每个请求大概3~4条每秒就是200条日志。如果每条平均100字节一天就是1.7GB。而INFO级别下同样的爬虫一天的日志量通常在200MB以内。差距是数量级的。但也不能只看数量。生产环境如果完全不开INFO很多关键信息会丢失。比如spider_opened和spider_closed是INFO级别item_scraped如果是通过LogStats输出的也是INFO级别这些是你判断爬虫是否健康的核心依据。所以我的建议是生产环境默认INFO频繁出错的环节单独用logger.warning或logger.error输出既控制量又不丢关键信息。3. 理解Scrapy的扩展机制日志系统背后的推手3.1 Scrapy扩展是什么为什么日志要依赖扩展很多人在热词里搜scrapy中extensions是什么其实就是没搞懂Scrapy里那套插件机制。Scrapy扩展Extension本质上是普通的Python类通过from_crawler类方法获得crawler实例然后借助crawler.signals.connect订阅爬虫生命周期中的各种信号比如spider_opened、spider_closed、item_scraped、response_received等在这些事件发生时执行自己的逻辑。日志和统计数据强相关而Scrapy的统计数据Stats Collector本身就是一个跨组件的状态容器所以日志功能天然适合用扩展来实现。最典型的例子是Scrapy内置的LogStats扩展它会在爬虫运行期间每隔一段时间输出一条类似这样的日志2024-06-18 10:30:00 [scrapy.extensions.logstats] INFO: Crawled 1200 pages (at 4 pages/min), scraped 850 items (at 3 items/min)这条日志不是引擎自动打的就是LogStats这个扩展在收到定时信号后从Stats Collector里取出数据通过logger输出的一条INFO消息。理解这一点你在解决日志不输出的问题时就会多一个排查方向是不是自定义扩展或默认扩展被禁用了Scrapy里有EXTENSIONS_BASE这个默认扩展集合里面包含了LogStats、CoreStats、Debugger等。你自己添加扩展可以通过EXTENSIONS配置项而禁用默认扩展也可以在这个配置里显式设为None。3.2 手写一个日志统计扩展按站点和状态码输出理解了机制我们就直接实操。下面这个扩展解决的问题很典型大型爬虫往往要跑多个站点你会非常需要知道每个站点的响应状态码分布、Item产出速率。Scrapy标准LogStats只给总量不给细分维度所以我们自己写一个扩展。import logging from collections import Counter, defaultdict from scrapy import signals logger logging.getLogger(crawler.site_health) class SiteStatsLogExtension: def __init__(self, crawler, log_every500): self.crawler crawler self.stats crawler.stats self.log_every log_every self.response_counter Counter() self.item_counter defaultdict(int) self.total_count 0 classmethod def from_crawler(cls, crawler): ext cls(crawler, crawler.settings.getint(SITE_STATS_LOG_EVERY, 500)) crawler.signals.connect(ext.spider_opened, signals.spider_opened) crawler.signals.connect(ext.response_received, signals.response_received) crawler.signals.connect(ext.item_scraped, signals.item_scraped) crawler.signals.connect(ext.spider_closed, signals.spider_closed) return ext def spider_opened(self, spider): logger.info(site stats module started, log every %d events, self.log_every) def response_received(self, response, **kwargs): site getattr(response, site_name, None) or response.url.split(/)[2] self.response_counter[(site, response.status)] 1 self.total_count 1 if self.total_count % self.log_every 0: self._emit_current_stats(spider_hint) def item_scraped(self, item, spider, **kwargs): site getattr(spider, site_name, None) or spider.name self.item_counter[site] 1 def _emit_current_stats(self, spider_hint): resp_summary { f{site}:{status}: cnt for (site, status), cnt in self.response_counter.items() } item_summary dict(self.item_counter) logger.info( site health snapshot responses%s items%s, resp_summary, item_summary, ) def spider_closed(self, spider, reason): self._emit_current_stats(spider_hintspider.name) logger.info(site stats module closed, total events %d, self.total_count)然后在settings.py里注册这个扩展EXTENSIONS { myproject.extensions.SiteStatsLogExtension: 500, }数字500表示优先级数字越小越早执行。这样在爬虫跑起来后每处理500个响应就会输出一条包含状态码分布和item数量的JSON风格日志配合第4章的结构化输出可以直接拿去喂给日志平台做告警。注意事项有两个。第一response_received信号携带的response在中间件里不一定有site_name属性所以我在代码里做了兜底——取URL的域名。这在实际运行中很关键不然扩展刚上线就会因为AttributeError导致整个爬虫挂掉。第二扩展里的异常处理不能省略如果_emit_current_stats内部出问题也不能让它影响主流程可以在方法体外面套一层try/except生产环境的扩展代码必须默认日志系统不能拖垮爬虫主线。4. 生产环境日志配置结构化、滚动与集中采集4.1 文件无限增长的坑滚动策略与handler替换回到第一章那个事故上根治办法就是给日志加滚动。但Scrapy的LOG_FILE配置项只创建FileHandler并不提供滚动能力所以需要自定义handler。这里有一个关键的实现前提Scrapy的configure_logging()会在crawler创建时运行如果你只是在settings.py顶层直接往root logger加handler很可能被它清掉。我踩过这个坑最后采用的稳妥方案是写一个扩展监听engine_started信号在日志系统初始化完成后替换root logger的handlers。import logging import os from logging.handlers import TimedRotatingFileHandler from scrapy import signals class LogRotationExtension: def __init__(self, log_dir, backup_days): self.log_dir log_dir self.backup_days backup_days classmethod def from_crawler(cls, crawler): ext cls( log_dircrawler.settings.get(LOG_DIR, logs), backup_dayscrawler.settings.getint(LOG_BACKUP_DAYS, 7), ) crawler.signals.connect(ext.engine_started, signals.engine_started) return ext def engine_started(self): root logging.getLogger() # 移除Scrapy默认添加的handler避免重复输出 for handler in root.handlers[:]: root.removeHandler(handler) os.makedirs(self.log_dir, exist_okTrue) formatter logging.Formatter( %(asctime)s [%(name)s] %(levelname)s: %(message)s, datefmt%Y-%m-%d %H:%M:%S,%f, ) file_handler TimedRotatingFileHandler( os.path.join(self.log_dir, scrapy.log), whenmidnight, backupCountself.backup_days, encodingutf-8, ) file_handler.setFormatter(formatter) root.addHandler(file_handler) console_handler logging.StreamHandler() console_handler.setFormatter(formatter) root.addHandler(console_handler)TimedRotatingFileHandler的whenmidnight表示每天零点切割backupCount7保留最近7个日志文件自动删除更早的。如果一台机器上日志写入量很大也可以改用RotatingFileHandler按文件大小切割比如单文件超过500MB切一个。这两种方案都能解决磁盘被写满的问题。替换handler时注意root.handlers[:]的切片复制是为了边遍历边删除直接遍历原列表会出问题。另外因为扩展的from_crawler在日志配置之后执行engine_started在爬虫引擎启动时才触发所以这个替换是安全的不会与Scrapy默认handler的初始化逻辑产生竞态冲突。4.2 结构化日志输出让每一条日志都能被程序解析生产环境的日志不应该只是给人看的还要能被采集、检索、统计。最强的做法是把日志输出成JSON格式。这样后续接入ELK或Loki时不需要写一堆grok解析规则直接按字段查就行。实现方式是用自定义Formatter。下面是我项目里在用的一个轻量实现不依赖第三方库import json import logging class JsonFormatter(logging.Formatter): def format(self, record): data { timestamp: self.formatTime(record, self.datefmt), logger: record.name, level: record.levelname, message: record.getMessage(), } if record.exc_info: data[exc_info] self.formatException(record.exc_info) return json.dumps(data, ensure_asciiFalse)然后在上一节的扩展里把file_handler.setFormatter(JsonFormatter())替换掉普通Formatter。控制台仍然可以用人类可读的Formatter文件用JSON这样兼顾排查和机器采集。这里有一个细节message里如果包含对象json.dumps会被类型卡住。我在生产里只允许字符串、数字、字典和列表有一个简单的兜底办法对message做str()强制转换但这样嵌套结构就不好看了。更干净的做法是在写入日志时统一用logger.info(xxx, extra{payload: {...}})然后在Formatter里拼装。总之日志平台字段越多后续监控告警越灵活。ensure_asciiFalse必须加上不然中文全变成\u转义序列看起来非常痛苦。这是一行必须记住的代码。4.3 敏感信息脱敏与记录边界爬虫日志经常会把URL、Cookie、Token、请求参数一起打出来这在本地没问题但生产环境的日志往往会被采集到统一的日志平台这就有信息泄露风险。我在日志系统中做了两层防护。第一层在可能涉及敏感信息的日志位置不打印完整内容。比如请求头里的Cookie就用logger.debug(cookie: ***)或者只打前几个字符。但代码是很多人写的靠自觉不可靠。第二层更稳妥的办法是加Filter。Filter可以在日志事件到达handler之前修改或丢弃消息。下面这个Filter会把常见敏感字段的值替换成掩码import re class SensitiveDataFilter(logging.Filter): def __init__(self, patternsNone): super().__init__() self.patterns patterns or [ (r(cookie[:]\s*)[^;\s], r\1***), (r(token[:]\s*)[^\s], r\1***), (r(password[:]\s*)[^\s], r\1***), ] def filter(self, record): msg record.getMessage() for pattern, repl in self.patterns: msg re.sub(pattern, repl, msg, flagsre.IGNORECASE) record.msg msg record.args () return True这个Filter要添加到所有输出到外部的handler上而不是只加在root logger上。如果你只加在一个handler上控制台能看到原始信息、日志平台只能看到脱敏信息这在某些场景下是有意为之的但要注意统一不然排查问题时会对着脱敏后的日志干瞪眼。4.4 日志分析工具选型日志采集和分析是生产环境绕不开的一环。如果项目规模不大单机几台服务器我推荐轻量方案Filebeat Loki Grafana。Filebeat负责读日志文件Loki负责存储和索引Grafana做可视化。这套方案比ELK轻得多对内存的占用只有ELK的几分之一尤其适合小团队自己维护。如果公司已经有ELKElasticsearch Logstash Kibana那就直接接入Filebeat把日志推到Logstash或者用Elastic Agent直接发到ES。因为日志已经是JSON结构化不需要再在Logstash里写grok解析整个链路会很流畅。关于AI工具精准分析日志我的态度是AI适合做辅助排查、发现异常模式、解释报错堆栈但前提是日志必须结构和采集做得好。如果日志是一堆无规则的文本任何AI工具也很难榨出有效信息。所以第一步永远是先把日志结构化和集中化然后再考虑让AI帮你从海量日志里找线索。我自己用下来觉得AI在给出一段报错、让它猜测可能原因这个场景效率很高但在实时监控告警上还是规则和指标更可靠。5. 生产环境实操一个可直接落地的完整配置5.1 完整配置包settings、扩展、启动命令把前面几章的东西串起来我现在给出一个可以直接抄的配置包。项目的目录结构大致是这样myproject/ ├── scrapy.cfg ├── myproject/ │ ├── settings.py │ ├── extensions/ │ │ ├── __init__.py │ │ ├── log_rotation.py │ │ └── site_stats.py │ └── spiders/settings.py里这样写LOG_ENABLED True LOG_LEVEL INFO LOG_FILE_MODE ab LOG_ENCODING utf-8 LOG_SHORT_NAMES False # 自定义日志扩展 EXTENSIONS { myproject.extensions.log_rotation.LogRotationExtension: 100, myproject.extensions.site_stats.SiteStatsLogExtension: 500, } # 扩展用到的自定义配置 LOG_DIR logs LOG_BACKUP_DAYS 7 SITE_STATS_LOG_EVERY 500这里的优先级数字要注意LogRotationExtension的优先级是100SiteStatsLogExtension是500数字小先执行。滚动日志的初始化在engine_started时执行而SiteStats在spider_opened时才开始统计两者不会冲突。如果你还用了playwright抓动态页面尤其是带iframe的复杂页面记住一个经验给每次iframe上下文切换和页面加载的关键节点打上spider.info级别的日志但别在请求循环里打印完整DOM。我处理过一个案例爬虫在抓某个嵌套三层iframe的页面时偶尔超时就是靠日志里记录的iframe加载状态才确认是某个广告iframe一直在刷接口导致的这种问题靠肉眼是看不出来的。5.2 验证与性能压测日志系统的瓶颈在哪里配置完之后不要直接上生产先做两件验证日志是否按预期切分以及日志IO对爬虫吞吐的影响。切分验证很简单手动改系统时间或者触发一次midnight切割比较麻烦可以用whenS和interval3600临时跑一小时验证或者干脆把when设成H每小时一切在生产上也够用我更喜欢按小时切割便于按小时粒度去回溯问题。验证输出观察logs/scrapy.log.2024-06-18这类带日期的归档文件是否生成以及scrapy.log本身是否被清空重建。性能方面我的实测经验是单进程500QPS以内同步FileHandler没有任何压力超过1000QPS日志写入会开始拖累主流程尤其是每个请求打多条DEBUG时更明显。解决方案有两个方向一是降低日志级别、减少日志事件数量二是用异步handler比如QueueHandler配合后台线程消费。简单可用的异步方案代码import logging import queue from logging.handlers import QueueHandler, QueueListener log_queue queue.Queue(-1) queue_handler QueueHandler(log_queue) queue_listener QueueListener( queue_handler, file_handler, console_handler, respect_handler_levelTrue, ) queue_listener.start()把queue_listener.start()放在扩展的engine_started里然后把queue_handler作为root logger的唯一handler。这样主线程把日志事件丢进队列就立刻返回真正写文件的IO在后台线程做。压测下来在1200QPS的场景下异步方案让爬虫吞吐几乎没有下降。但这个方案的代价是进程退出时可能丢日志所以要在爬虫关闭时调用queue_listener.stop()确保队列消费完。这里就不展开完整生命周期管理了生产使用务必在spider_closed或close_spider里处理。5.3 监控告警日志不只是用来事后排查日志的最高级用法是变成实时监控信号。我习惯在项目里实现一个爬虫心跳日志每隔固定时间如果爬虫还在正常产出item就输出一条心跳日志如果连续多个心跳周期没有产出监控平台就会告警。实现思路还是依赖Stats Collector。在上一节的SiteStats扩展基础上增加一个计时逻辑import time class HeartbeatMixin: def __init__(self, crawler, heartbeat_interval300): self.crawler crawler self.heartbeat_interval heartbeat_interval self.last_item_time time.time() def item_scraped(self, item, spider, **kwargs): self.last_item_time time.time() # 原有统计逻辑... def _check_heartbeat(self, spider): idle_seconds time.time() - self.last_item_time if idle_seconds self.heartbeat_interval: logger.warning( heartbeat missing: spider%s idle_seconds%s, spider.name, idle_seconds, )然后在settings里用extension连接一个定时信号或者更简单地在item_scraped里检查时间差。因为爬虫总是在处理item所以这个检查不需要额外定时器。如果爬虫卡死item_scraped本身就不会触发但heartbeat missing日志也会消失所以需要外部监控配合——监控平台如果没有在5分钟内收到该爬虫的任何日志就触发告警。这套逻辑我在多个项目里都用属于投资小、回报高的一类监控。另一类告警是基于错误率。我会让扩展维护一个错误状态码统计比如在一个窗口内5xx比例超过20%就通过logger.error输出一条特定前缀的告警日志由监控平台直接截获转发。这样做的好处是业务告警逻辑完全收敛在爬虫项目里运维侧只需要配置一条匹配规则。6. 常见问题排查实录8个真实Case速查日志系统出问题翻文档往往没用因为网上都是照抄配置不讲为什么。下面这8个Case是我这几年实际遇到过的整理成速查表。现象直接原因解决办法设置了LOG_FILE但文件是空的LOG_ENABLED被改成False检查settings和启动参数控制台突然没有日志设置了LOG_FILE后默认只写文件按第4章方式自定义双handler日志隔一段时间翻倍增长自定义扩展重复添加handler先remove再add做幂等处理磁盘被日志撑爆使用了LOG_FILE没有轮转用TimedRotatingFileHandler日志中文乱码FileHandler默认编码不对LOG_ENCODINGutf-8 或创建handler时指定日志级别改了不生效命令行-L参数优先级更高检查crawl命令完整参数某些中间件的日志看不到该中间件用的是第三方logger确认root logger级别必要时单独设level爬虫崩了但日志里没有堆栈异常发生在信号回调里被吞掉在扩展和信号处理里增加try/except并logger.exception逐条展开说一些宝贵经验。第一个设置LOG_FILE后文件为空我排查过好几次最后发现是settings.py里某个环境判断逻辑在这个环境下把LOG_ENABLED设成了False。不要觉得这个配置没人动生产环境经常有多套配置互相覆盖。第二个控制台没日志很多人以为是代码问题其实是Scrapy文件或控制台二选一的默认逻辑。如果你既想保留控制台输出又想写文件就别用LOG_FILE改用自定义handler。第三个日志翻倍增长。这个最有隐蔽性因为不是报错只是日志从某次上线后突然暴增。最后查到是一个监控扩展重复执行了root.addHandler每注册一次就多一个handler同一条日志被写N遍。解决办法是在addHandler之前先遍历移除同类handler或者维护一个标志变量。第四个磁盘被日志撑爆就是第一章的场景。不重复了。第五个中文乱码。Scrapy的LOG_FILE用的是系统默认编码在有些服务器上是ASCII中文直接变成问号或抛异常。设置LOG_ENCODING utf-8即可。自定义handler时记得在FileHandler(..., encodingutf-8)里显式指定。第六个日志级别不生效。有一回我一个爬虫里设置custom_settings {LOG_LEVEL: DEBUG}但跑起来还是INFO。原因是我在命令行用了-L INFO命令行优先级高于custom_settings。所以要检查完整启动命令别只盯着代码。第七个第三方库日志丢失。常见的比如selenium的webdriver_manager日志、requests的urllib3日志。Scrapy的root logger默认会捕获它们但有些库创建了独立的logger并设置了propagate False导致日志不会冒泡到root。处理办法是显式设置该logger的级别和handler比如logging.getLogger(urllib3).setLevel(logging.WARNING)。第八个爬虫崩了但没堆栈。这个坑在自定义信号回调里最典型。信号回调如果抛出异常经常会被Twisted的日志系统捕获并打到一个独立的logger里如果不仔细看你只会看到spider关闭不知道异常在哪。我在所有扩展的公共方法里都加了兜底def _safe_log(self, func, *args, **kwargs): try: func(*args, **kwargs) except Exception: logger.exception(extension method failed: %s, func.__name__)日志系统本身的故障不能影响爬虫主流程这是生产环境的底线。最后再分享一个小技巧。排查日志问题时我通常会先在本地用scrapy crawl myspider -L DEBUG -s LOG_ENABLEDTrue跑一小段把全部日志落到一个临时文件里然后对比生产环境的差异。这比直接改生产配置快很多。生产环境配置日志是个慢功夫一次配好、持续观察、逐步优化比出问题再救火舒服太多了。希望这篇内容能让你在配置Scrapy日志时少踩几个坑。