3.3 Handler配置
3.3.1 handler配置格式输出
$ cat log5.py import logging logger = logging.getLogger(__name__) logger.setLevel(level=logging.INFO) handler = logging.FileHandler('output.log') formatter = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s') handler.setFormatter(formatter) logger.addHandler(handler) logger.info('This is a log info') logger.debug('Debugging') logger.warning('Warning exists') logger.info('Finish')
没有再使用 basicConfig 全局配置,而是先声明了一个 Logger 对象,然后指定了其对应的 Handler 为 FileHandler 对象,然后 Handler 对象还单独指定了 Formatter 对象单独配置输出格式,最后给 Logger 对象添加对应的 Handler 即可,最后可以发现日志就会被输出到 output.log 中.
$ python log5.py $ cat output.log 2020-05-17 13:58:41,039 - __main__ - INFO - This is a log info 2020-05-17 13:58:41,039 - __main__ - WARNING - Warning exists 2020-05-17 13:58:41,039 - __main__ - INFO - Finish 2020-05-17 14:01:15,909 - __main__ - INFO - This is a log info 2020-05-17 14:01:15,909 - __main__ - WARNING - Warning exists 2020-05-17 14:01:15,909 - __main__ - INFO - Finish
3.3.2 多种handle输出
$ cat log6.py import logging from logging.handlers import HTTPHandler import sys logger = logging.getLogger(__name__) logger.setLevel(level=logging.DEBUG) # StreamHandler stream_handler = logging.StreamHandler(sys.stdout) stream_handler.setLevel(level=logging.DEBUG) logger.addHandler(stream_handler) # FileHandler file_handler = logging.FileHandler('output.log') file_handler.setLevel(level=logging.INFO) formatter = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s') file_handler.setFormatter(formatter) logger.addHandler(file_handler) # HTTPHandler http_handler = HTTPHandler(host='localhost:80', url='log', method='POST') logger.addHandler(http_handler) # Log logger.info('This is a log info') logger.debug('Debugging') logger.warning('Warning exists') logger.info('Finish')
输出:
$ python log6.py This is a log info Debugging Warning exists Finish $ cat output.log 2020-05-17 14:05:48,809 - __main__ - INFO - This is a log info 2020-05-17 14:05:48,849 - __main__ - WARNING - Warning exists 2020-05-17 14:05:48,851 - __main__ - INFO - Finish
3.4 捕获 Traceback
$ cat log7.py import logging logger = logging.getLogger(__name__) logger.setLevel(level=logging.DEBUG) # Formatter formatter = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s') # FileHandler file_handler = logging.FileHandler('result.log') file_handler.setFormatter(formatter) logger.addHandler(file_handler) # StreamHandler stream_handler = logging.StreamHandler() stream_handler.setFormatter(formatter) logger.addHandler(stream_handler) # Log logger.info('Start') logger.warning('Something maybe fail.') try: result = 10 / 0 except Exception: logger.error('Faild to get result', exc_info=True) #logger.error('Faild to get result') logger.info('Finished')
在 error() 方法中添加了一个参数,将 exc_info 设置为了 True,这样我们就可以输出执行过程中的信息了,即完整的 Traceback 信息。
$ python log7.py 2020-05-17 14:13:02,217 - __main__ - INFO - Start 2020-05-17 14:13:02,217 - __main__ - WARNING - Something maybe fail. 2020-05-17 14:13:02,217 - __main__ - ERROR - Faild to get result Traceback (most recent call last): File "log7.py", line 23, in <module> result = 10 / 0 ZeroDivisionError: integer division or modulo by zero 2020-05-17 14:13:02,217 - __main__ - INFO - Finished
3.5 配置共享
在写项目的时候,我们肯定会将许多配置放置在许多模块下面,这时如果我们每个文件都来配置 logging 配置那就太繁琐了,logging 模块提供了父子模块共享配置的机制,会根据 Logger 的名称来自动加载父模块的配置。
$ vim main.py import logging import core logger = logging.getLogger('main') logger.setLevel(level=logging.DEBUG) # Handler handler = logging.FileHandler('result.log') handler.setLevel(logging.INFO) formatter = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s') handler.setFormatter(formatter) logger.addHandler(handler) logger.info('Main Info') logger.debug('Main Debug') logger.error('Main Error') core.run()
这里我们配置了日志的输出格式和文件路径,同时定义了 Logger 的名称为 main,然后引入了另外一个模块 core,最后调用了 core 的 run() 方法。
$ vim core.py import logging logger = logging.getLogger('main.core') def run(): logger.info('Core Info') logger.debug('Core Debug') logger.error('Core Error')
这里我们定义了 Logger 的名称为 main.core,注意这里开头是 main,即刚才我们在 main.py 里面的 Logger 的名称,这样 core.py 里面的 Logger 就会复用 main.py 里面的 Logger 配置,而不用再去配置一次了.
$ python main.py $ cat result.log 2020-05-17 14:30:48,559 - main - INFO - Main Info 2020-05-17 14:30:48,559 - main - ERROR - Main Error 2020-05-17 14:30:48,559 - main.core - INFO - Core Info 2020-05-17 14:30:48,559 - main.core - ERROR - Core Error
3.6 文件配置
常见的配置文件有 ini 格式、yaml 格式、JSON 格式,这里以yaml为例。将配置写入到配置文件,然后运行时读取配置文件里面的配置,这样是更方便管理和维护.
3.6.1 yaml配置文件
$ vim config.yaml version: 1 formatters: brief: format: "%(asctime)s - %(message)s" simple: format: "%(asctime)s - %(name)s - %(levelname)s - %(message)s" handlers: console: class : logging.StreamHandler formatter: brief level : INFO stream : ext://sys.stdout file: class : logging.FileHandler formatter: simple level: DEBUG filename: debug.log error: class: logging.handlers.RotatingFileHandler level: ERROR formatter: simple filename: error.log maxBytes: 10485760 backupCount: 20 encoding: utf8 loggers: main.core: level: DEBUG handlers: [console, file, error] root: level: DEBUG handlers: [console]
这里我们定义了 formatters、handlers、loggers、root 等模块,实际上对应的就是各个 Formatter、Handler、Logger 的配置,参数和它们的构造方法都是相同的。
定义一个主入口文件,main.py.
$ vim main.py import logging import core import yaml import logging.config import os import io def setup_logging(default_path='config.yaml', default_level=logging.INFO): path = default_path if os.path.exists(path): with io.open(path, 'r', encoding='utf-8') as f: config = yaml.load(f) logging.config.dictConfig(config) else: logging.basicConfig(level=default_level) def log(): logging.debug('Start') logging.info('Exec') logging.info('Finished') if __name__ == '__main__': yaml_path = 'config.yaml' setup_logging(yaml_path) log() core.run()
这里我们定义了一个 setup_logging() 方法,里面读取了 yaml 文件的配置,然后通过 dictConfig() 方法将配置项传给了 logging 模块进行全局初始化。
另外这个模块还引入了另外一个模块 core,所以我们定义 core.py 如下:
import logging logger = logging.getLogger('main.core') def run(): logger.info('Core Info') logger.debug('Core Debug') logger.error('Core Error')
输出:
$ python main.py 2020-05-17 14:47:09,905 - Exec 2020-05-17 14:47:09,905 - Finished 2020-05-17 14:47:09,905 - Core Info 2020-05-17 14:47:09,905 - Core Info 2020-05-17 14:47:09,905 - Core Error 2020-05-17 14:47:09,905 - Core Error $ cat error.log 2020-05-17 14:47:09,905 - main.core - ERROR - Core Error $ cat debug.log 2020-05-17 14:47:09,905 - main.core - INFO - Core Info 2020-05-17 14:47:09,905 - main.core - DEBUG - Core Debug 2020-05-17 14:47:09,905 - main.core - ERROR - Core Error
3.6.2 ini配置文件
下面只展示了 ini 格式和 yaml 格式的配置。
test.ini 文件 [loggers] keys=root,sampleLogger [handlers] keys=consoleHandler [formatters] keys=sampleFormatter [logger_root] level=DEBUG handlers=consoleHandler [logger_sampleLogger] level=DEBUG handlers=consoleHandler qualname=sampleLogger propagate=0 [handler_consoleHandler] class=StreamHandler level=DEBUG formatter=sampleFormatter args=(sys.stdout,) [formatter_sampleFormatter] format=%(asctime)s - %(name)s - %(levelname)s - %(message)s
testinit.py 文件
import logging.config logging.config.fileConfig(fname='test.ini', disable_existing_loggers=False) logger = logging.getLogger("sampleLogger") logger.info('Core Info') logger.debug('Core Debug') logger.error('Core Error')
输出:
import logging.config logging.config.fileConfig(fname='test.ini', disable_existing_loggers=False) logger = logging.getLogger("sampleLogger") logger.info('Core Info') logger.debug('Core Debug') logger.error('Core Error')
3.7 字符串拼接
format() 构造与占位符用%
$ log8.py import logging logging.basicConfig(level=logging.DEBUG, format='%(asctime)s - %(name)s - %(levelname)s - %(message)s') # bad logging.debug('Hello {0}, {1}!'.format('World', 'Congratulations')) # good logging.debug('Hello %s, %s!', 'World', 'Congratulations')
运行结果如下:
$ python log8.py 2020-05-17 14:55:29,709 - root - DEBUG - Hello World, Congratulations! 2020-05-17 14:55:29,709 - root - DEBUG - Hello World, Congratulations!
3.8 异常处理
$ cat log9.py import logging logging.basicConfig(level=logging.DEBUG, format='%(asctime)s - %(name)s - %(levelname)s - %(message)s') try: result = 5 / 0 except Exception as e: # bad logging.error('Error: %s', e) # good logging.error('Error', exc_info=True) # good logging.exception('Error')
结果输出:
$ python log9.py 2020-05-17 14:56:51,027 - root - ERROR - Error: integer division or modulo by zero 2020-05-17 14:56:51,027 - root - ERROR - Error Traceback (most recent call last): File "log9.py", line 6, in <module> result = 5 / 0 ZeroDivisionError: integer division or modulo by zero 2020-05-17 14:56:51,028 - root - ERROR - Error Traceback (most recent call last): File "log9.py", line 6, in <module> result = 5 / 0 ZeroDivisionError: integer division or modulo by zero
3.9 日志文件按照时间划分或者按照大小划分
如果将日志保存在一个文件中,那么时间一长,或者日志一多,单个日志文件就会很大,既不利于备份,也不利于查看。我们会想到能不能按照时间或者大小对日志文件进行划分呢?答案肯定是可以的,并且还很简单,logging 考虑到了我们这个需求。logging.handlers 文件中提供了 TimedRotatingFileHandler 和 RotatingFileHandler 类分别可以实现按时间和大小划分。打开这个 handles 文件,可以看到还有其他功能的 Handler 类,它们都继承自基类 BaseRotatingHandler。
3.9.1 TimedRotatingFileHandler构造函数
定义如下:
TimedRotatingFileHandler(filename [,when [,interval [,backupCount]]])
示例:
# 每隔 1小时 划分一个日志文件,interval 是时间间隔,备份文件为 10 个 handler2 = logging.handlers.TimedRotatingFileHandler("test.log", when="H", interval=1, backupCount=10)
- filename: 是输出日志文件名的前缀,比如log/myapp.log
- when :是一个字符串的定义如下:
“S”: Seconds
“M”: Minutes
“H”: Hours
“D”: Days
“W”: Week day (0=Monday)
“midnight”: Roll over at midnight
- interval :是指等待多少个单位when的时间后,Logger会自动重建文件
- backupCount:是保留日志个数。默认的0是不会自动删除掉日志。若设3,则在文件的创建过程中库会判断是否有超过这个3,若超过,则会从最先创建的开始删除。
$ cat log10.py #!/usr/bin/python #---coding:utf-8 import logging import logging.handlers import datetime,time #logging 初始化工作 logger = logging.getLogger("zjlogger") logger.setLevel(logging.DEBUG) # 添加TimedRotatingFileHandler # 定义一个1秒换一次log文件的handler # 保留3个旧log文件 rf_handler = logging.handlers.TimedRotatingFileHandler(filename="all.log",when='S',interval=1,\ backupCount=3) rf_handler.setFormatter(logging.Formatter("%(asctime)s - %(levelname)s - %(filename)s[:%(lineno)d] - %(message)s")) #在控制台打印日志 handler = logging.StreamHandler() handler.setLevel(logging.DEBUG) handler.setFormatter(logging.Formatter("%(asctime)s - %(levelname)s - %(message)s")) logger.addHandler(rf_handler) logger.addHandler(handler) while True: logger.debug('debug message') logger.info('info message') logger.warning('warning message') logger.error('error message') logger.critical('critical message') time.sleep(1)
$ ls all.log all.log.2020-05-17_15-21-55 all.log.2020-05-17_15-21-56 all.log.2020-05-17_15-21-57 log10.py
3.9.2 RotatingFileHandler 构造函数
示例:
# 每隔 1000 Byte 划分一个日志文件,备份文件为 3 个 file_handler = logging.handlers.RotatingFileHandler("test.log", mode="w", maxBytes=1000, backupCount=3, encoding="utf-8") 复制代码
$ cat log11.py #!coding:utf-8 #!/usr/bin/env python import time import logging import logging.handlers # logging初始化工作 logging.basicConfig() # myapp的初始化工作 myapp = logging.getLogger('myapp') myapp.setLevel(logging.INFO) # 写入文件,如果文件超过100个Bytes,仅保留5个文件。 handler = logging.handlers.RotatingFileHandler( 'logs/myapp.log', maxBytes=100, backupCount=5) myapp.addHandler(handler) while True: time.sleep(0.01) myapp.info("file test")
输出:
$ python log11.py INFO:myapp:file test INFO:myapp:file test INFO:myapp:file test INFO:myapp:file test ..... $ ls logs myapp.log myapp.log.1 myapp.log.2 myapp.log.3 myapp.log.4 myapp.log.5
3.10 logging.disable暂时禁止日志输出
运行测试代码时,我不想登录到文件或控制台
在运行测试代码时将日志输出到文件或控制台通常会感到非常烦人。
如果将其输出到文件,则可以将其保留,但是如果将其记录到控制台,将很难理解测试执行的进度和结果。
而且,由于日志本身就是输入/输出,因此花费额外的测试执行时间没有错
logging.disable会忽略低于指定日志级别的日志输出
Python的日志记录模块定义了一个名为disable的函数,该函数将日志级别作为参数传递。例如
import logging logging.disable(logging.FATAL)
如果这样做,将不会输出FATAL
以下的日志。
换句话说,由于它低于最高级别FATAL,因此实际上没有日志输出。
反之亦然
import loggging logging.disable(logging.NOTSET)
NOTSET
是最低的日志级别,因此这与取消抑制日志相同。
我使用setUp和tearDown使用logging.disable
考虑到这一点,您可以执行以下操作来在编写测试代码时暂时停止日志输出。
import logging import unittest class FooTest(unittest.TestCase): def setUp(self): logging.disable(logging.FATAL) def tearDown(self): logging.disable(logging.NOTSET) def test(self):
参考: