Fork me on GitHub

使用logging管理爬虫

发表于 | 分类于 
这是崔斯特的第二十四篇原创文章

使用日志记录程序运行状态

文档

日志 模块自2.3版本开始便是Python标准库的一部分。它被简洁的描述在 PEP 282。 众所周知，除了 基础日志指南 部分，该文档并不容易阅读。

日志的两个目的：

  • 诊断日志 记录与应用程序操作相关的日志。例如，用户遇到的报错信息， 可通过搜索诊断日志获得上下文信息。
  • 审计日志 为商业分析而记录的日志。从审计日志中，可提取用户的交易信息， 并结合其他用户资料构成用户报告或者用来优化商业目标。

… 或者打印?

当需要在命令行应用中显示帮助文档时， 打印 是一个相对于日志更好的选择。 而在其他时候，日志总能优于 打印 ，理由如下：

  • 日志事件产生的 日志记录 ，包含清晰可用的诊断信息，如文件名称、路径、函数名和行号等。
  • 包含日志模块的应用，默认可通过根记录器对应用的日志流进行访问，除非您将日志过滤了。
  • 可通过 logging.Logger.setLevel() 方法有选择地记录日志， 或可通过设置 logging.Logger.disabled 属性为 True 来禁用。

库中的日志

日志指南 中含 库日志配置 的说明。由于是 用户 ，而非库来指明如何响应日志事件， 因此这里有一个值得反复说明的忠告：

注解
强烈建议不要向您的库日志中加入除NullHandler外的其它处理程序。

在库中，声明日志的最佳方式是通过 __name__ 全局变量： logging 模块通过点(dot)运算符创建层级排列的日志，因此，用 __name__ 可以避免名字冲突。

以下是一个来自 requests 资源 的最佳实践的例子 —— 把它放置在您的 __init__.py 文件中

1
2
import logging
logging.getLogger(__name__).addHandler(logging.NullHandler())

应用程序中的日志

应用程序开发的权威指南， 应用的12要素 ，也在其中一节描述了 日志的作用 。它特别强调将日志视为事件流， 并将其发送至由应用环境所处理的标准输出中。

配置日志至少有以下三种方式：

  • 使用INI格式文件：
    • 优点: 使用 logging.config.listen() 函数监听socket，可在运行过程中更新配置
    • 缺点: 通过源码控制日志配置较少（ 例如 子类化定制的过滤器或记录器）。
  • 使用字典或JSON格式文件：
    • 优点: 除了可在运行时动态更新，在Python 2.6之后，还可通过 json 模块从其它文件中导入配置。
    • 缺点: 很难通过源码控制日志配置。
  • 使用源码：
    • 优点: 对配置绝对的控制。
    • 缺点: 对配置的更改需要对源码进行修改。

通过INI文件进行配置的例子

我们假设文件名为 logging_config.ini 。关于文件格式的更多细节，请参见 日志指南 中的 日志配置 部分。

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
[loggers]
keys=root
[handlers]
keys=stream_handler
[formatters]
keys=formatter
[logger_root]
level=DEBUG
handlers=stream_handler
[handler_stream_handler]
class=StreamHandler
level=DEBUG
formatter=formatter
args=(sys.stderr,)
[formatter_formatter]
format=%(asctime)s %(name)-12s %(levelname)-8s %(message)s

然后在源码中调用 logging.config.fileConfig() 方法：

1
2
3
4
5
6
import logging
from logging.config import fileConfig
fileConfig('logging_config.ini')
logger = logging.getLogger()
logger.debug('often makes a very good meal of %s', 'visiting tourists')

通过字典进行配置的例子

Python 2.7中，您可以使用字典实现详细配置。PEP 391 包含了一系列字典配置的强制和 非强制的元素。

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
import logging
from logging.config import dictConfig
logging_config = dict(
    version = 1,
    formatters = {
        'f': {'format':
              '%(asctime)s %(name)-12s %(levelname)-8s %(message)s'}
        },
    handlers = {
        'h': {'class': 'logging.StreamHandler',
              'formatter': 'f',
              'level': logging.DEBUG}
        },
    root = {
        'handlers': ['h'],
        'level': logging.DEBUG,
        },
)
dictConfig(logging_config)
logger = logging.getLogger()
logger.debug('often makes a very good meal of %s', 'visiting tourists')

通过源码直接配置的例子

1
2
3
4
5
6
7
8
9
10
11
import logging
logger = logging.getLogger()
handler = logging.StreamHandler()
formatter = logging.Formatter(
        '%(asctime)s %(name)-12s %(levelname)-8s %(message)s')
handler.setFormatter(formatter)
logger.addHandler(handler)
logger.setLevel(logging.DEBUG)
logger.debug('often makes a very good meal of %s', 'visiting tourists')

官方文档说完了，来看看具体的应用。

默认的日志级别设置为 WARNING （日志级别等级 CRITICAL > ERROR > WARNING > INFO > DEBUG > NOTSET）, 小于 WARNING 级别的日志都不输出, 大于等于 WARNING 级别的日志都会输出。

简单的将日志打印到屏幕

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
#!/usr/bin/env python
# -*- coding: utf8 -*-
import logging
if __name__ == '__main__':
    logging.basicConfig(level=logging.DEBUG,
    format='%(asctime)s %(filename)s [line:%(lineno)d] %(levelname)s %(message)s',
            datefmt='%a, %d %b %Y %H:%M:%S',
            filename='test.log',
            filemode='w')
    console = logging.StreamHandler()
    console.setLevel(logging.WARNING)
    formatter=logging.Formatter('%(name)-12s: %(levelname)-8s %(message)s')
    console.setFormatter(formatter)
    logging.getLogger('').addHandler(console)
    logging.debug('This is DEBUG')
    logging.info('This is INFO')
    logging.warning('This is WARNING')

输出:

1
root        : WARNING  This is WARNING

test.log文件中包含：

1
2
3
Mon, 15 Jan 2018 20:19:45 sfda.py [line:90] DEBUG This is DEBUG
Mon, 15 Jan 2018 20:19:45 sfda.py [line:91] INFO This is INFO
Mon, 15 Jan 2018 20:19:45 sfda.py [line:92] WARNING This is WARNING

注意：由于日志写入模式设置为 w ，因此重复运行时会将之前的日志清空。

logging.basicConfig 函数各参数:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
filename: 指定日志文件名
filemode: 和file函数意义相同，指定日志文件的打开模式，’w’或’a’
format: 指定输出的格式和内容，format可以输出很多有用信息，如上例所示:
%(levelno)s: 打印日志级别的数值
%(levelname)s: 打印日志级别名称
%(pathname)s: 打印当前执行程序的路径，其实就是sys.argv[0]
%(filename)s: 打印当前执行程序名
%(funcName)s: 打印日志的当前函数
%(lineno)d: 打印日志的当前行号
%(asctime)s: 打印日志的时间
%(thread)d: 打印线程ID
%(threadName)s: 打印线程名称
%(process)d: 打印进程ID
%(message)s: 打印日志信息
datefmt: 指定时间格式，同time.strftime()
level: 设置日志级别，默认为logging.WARNING
stream: 指定将日志的输出流，可以指定输出到sys.stderr,
sys.stdout或者文件，默认输出到sys.stderr，当stream和filename同时指定时，stream被忽略

logging 三大模块： Logger , Handler ， Format

logger

logger 通过 getLogger 函数得到， 可以在不同的模块中使用不同的 logger

1
2
3
import logging
logger = logging.getLogger(__name__)
logger.debug('some infomation')

Handler

handler 有多种， 可以记录到 console， 或者到文件， 文件也可以自动 rotate， 常用的几个 handler

  • StreamHandler 打印到终端
  • FileHandler 保存到文件
  • RotatingFileHandler 保存到文件， 达到一定大小之后备份文件。
  • TimedRotatingFileHandler 定时备份

Format

Formatter 对象设置日志信息最后的规则、结构和内容，默认的时间格式为 %Y-%m-%d %H:%M:%S

Scrapy 与 Logging

文档

Scrapy uses Python’s builtin logging system for event logging. We’ll provide some simple examples to get you started, but for more advanced use-cases it’s strongly suggested to read thoroughly its documentation.

Scrapy使用Python的内置日志记录系统进行事件日志记录。 我们将提供一些简单的示例来帮助您开始，但对于更高级的用例，强烈建议您仔细阅读其文档。

Log levels

  1. logging.CRITICAL - for critical errors (highest severity)
  2. logging.ERROR - for regular errors
  3. logging.WARNING - for warning messages
  4. logging.INFO - for informational messages
  5. logging.DEBUG - for debugging messages (lowest severity)

How to log messages

quick example

1
2
3
import logging
logger = logging.getLogger()
logger.warning("This is a warning")

Logging from Spiders

该记录器是使用Spider的名称创建的，但是您可以使用任何您想要的自定义Python记录器。 例如：

1
2
3
4
5
6
7
8
9
10
11
12
import logging
import scrapy
logger = logging.getLogger('mycustomlogger')
class MySpider(scrapy.Spider):
    name = 'myspider'
    start_urls = ['https://scrapinghub.com']
    def parse(self, response):
        logger.info('Parse function called on %s', response.url)

在middlewares中应用

1
2
3
4
5
6
7
8
import logging
logger = logging.getLogger(__name__)
class ProxyMiddleware(object):
    def process_request(self, request, spider):
        request.meta['proxy'] = random.choice(proxy_list)
        spider.logger.info('get ip: {}'.format(request.meta['proxy']))

使用Scrapy记录爬取日志

在 settings.py 中修改:

1
2
LOG_STDOUT = True
LOG_FILE = 'scrapy_log.txt'

然后开始运行爬虫，日志不会打印，会保存到 scrapy_log.txt 文件中。

使用errbacks在请求处理中捕获异常

请求的errback是在处理异常时被调用的函数。

它接收Twisted Failure实例作为第一个参数，可用于跟踪连接建立超时，DNS错误等。

这里有一个爬虫日志记录所有的错误和捕捉一些特定的错误，例子：

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
import scrapy
from scrapy.spidermiddlewares.httperror import HttpError
from twisted.internet.error import DNSLookupError
from twisted.internet.error import TimeoutError, TCPTimedOutError
class ErrbackSpider(scrapy.Spider):
    name = "errback_example"
    start_urls = [
        "http://www.httpbin.org/",              # HTTP 200 expected
        "http://www.httpbin.org/status/404",    # Not found error
        "http://www.httpbin.org/status/500",    # server issue
        "http://www.httpbin.org:12345/",        # non-responding host, timeout expected
        "http://www.httphttpbinbin.org/",       # DNS error expected
    ]
    def start_requests(self):
        for u in self.start_urls:
            yield scrapy.Request(u, callback=self.parse_httpbin,
                                    errback=self.errback_httpbin,
                                    dont_filter=True)
    def parse_httpbin(self, response):
        self.logger.info('Got successful response from {}'.format(response.url))
        # do something useful here...
    def errback_httpbin(self, failure):
        # log all failures
        self.logger.error(repr(failure))
        # in case you want to do something special for some errors,
        # you may need the failure's type:
        if failure.check(HttpError):
            # these exceptions come from HttpError spider middleware
            # you can get the non-200 response
            response = failure.value.response
            self.logger.error('HttpError on %s', response.url)
        elif failure.check(DNSLookupError):
            # this is the original request
            request = failure.request
            self.logger.error('DNSLookupError on %s', request.url)
        elif failure.check(TimeoutError, TCPTimedOutError):
            request = failure.request
            self.logger.error('TimeoutError on %s', request.url)