如何让Python（含Scrapy）日志显示在Heroku日志附加组件中

问题背景 #

我在Heroku上运行Python Scrapy程序，Scrapy依赖Python原生logging生成日志，代码中还使用print语句作为临时日志方案。本地运行或通过CLI进入Heroku实例执行代码时，能正常看到如下日志：

2024-04-04 13:20:28 [scrapy.core.engine] INFO: Spider opened
2024-04-04 13:20:28 [scrapy.extensions.logstats] INFO: Crawled 0 pages (at 0 pages/min), scraped 0 items (at 0 items/min)
2024-04-04 13:20:28 [scrapy.extensions.telnet] INFO: Telnet console listening on 127.0.0.1:6023
2024-04-04 13:20:28 [root] INFO: Searches left - 3601
This could be a random log from a print() statement

但安装Mezmo和Papertrail日志附加组件后，仅能看到系统日志：

Apr 4 09:18:45 paymosaic app[api] notice Release v40 created by user logdna@addons.heroku.com
Apr 4 09:18:45 paymosaic app[api] notice Update LOGDNA by logdna by user logdna@addons.heroku.com

Scrapy日志及print输出均未流入附加组件，需通过以下配置解决：

核心原因 #

Heroku日志收集系统仅捕获**标准输出(stdout)和标准错误(stderr)**的内容。Scrapy默认日志输出可能未定向到这两个流，再加上非交互式环境下print语句的缓冲机制，导致日志无法被正常收集。

具体配置步骤 #

1. 调整Scrapy日志配置，强制输出到stdout/stderr #

在Scrapy项目的settings.py中添加或修改以下代码：

import logging
from scrapy.utils.log import configure_logging

# 重置Scrapy日志配置，输出到stdout
configure_logging(install_root_handler=False)
logging.basicConfig(
    level=logging.INFO,
    format='%(asctime)s [%(name)s] %(levelname)s: %(message)s',
    handlers=[logging.StreamHandler()]
)

# 开启Scrapy日志重定向
LOG_LEVEL = 'INFO'
LOG_STDOUT = True  # 将Scrapy日志定向到stdout
LOG_STDERR = True  # 将错误日志定向到stderr

2. 禁用Python输出缓冲，确保print日志实时输出 #

Python在Heroku容器这类非交互式环境下会缓冲print输出，需通过以下方式禁用：

• 修改Procfile的启动命令，添加-u参数：

  worker: python -u -m scrapy crawl 你的爬虫名称
  

  或者如果用自定义脚本启动：

  worker: python -u your_scrapy_script.py
  

• 或者在代码入口处添加环境变量设置：

  import os
  os.environ['PYTHONUNBUFFERED'] = '1'
  

3. 验证日志收集是否生效 #

部署修改后的代码到Heroku，执行以下命令查看实时日志：

heroku logs --tail

如果能看到Scrapy和print的日志内容，说明配置成功，Mezmo/Papertrail会自动同步这些日志。

4. 检查日志附加组件的过滤规则 #

登录Mezmo或Papertrail后台，确认是否存在过滤规则屏蔽了app[worker]进程的日志，确保代码进程的日志未被排除。

内容的提问来源于stack exchange，提问作者Allen Y