logging | 凉薄的自动书记人偶

loggiing 模块

日志级别大小关系为：CRITICAL > ERROR > WARNING > INFO > DEBUG > NOTSET

级别	何时使用
`DEBUG`	细节信息，仅当诊断问题时适用。
`INFO`	确认程序按预期运行
`WARNING`	表明有已经或即将发生的意外（例如：磁盘空间不足）。程序仍按预期进行
`ERROR`	由于严重的问题，程序的某些功能已经不能正常执行
`CRITICAL`	严重的错误，表明程序已不能继续执行

默认级别是 WARNING 。

记录日志到文件

import logging

logging.basicConfig(filename='test.log',level=logging.DEBUG)

logging.debug('debug')
logging.info('info')
logging.warning('warning')
logging.error('error')

文件内容如下:

DEBUG:root:debug
INFO:root:info
WARNING:root:warning
ERROR:root:error

从多个模块记录日志

# mylib.py
import logging

def do_something():
    logging.info('Doing something')

# myapp.py
import logging
import mylib

def main():
    logging.basicConfig(filename='myapp.log', level=logging.INFO)
    logging.info('Started')
    mylib.do_something()
    logging.info('Finished')

if __name__ == '__main__':
    main()

记录变量数据

将可变数据合并到事件描述消息中使用旧的 %-s形式的字符串格式化

import logging

base_debug = '%s before you %s'
logging.debug(base_debug,'Look','leap')

自定义显示消息的格式

import logging

logging.basicConfig(format='%(levelname)s --- %(message)s',level=logging.DEBUG)

logging.debug('AAAA')
logging.info('BBBB')
logging.warning('CCCC')
# DEBUG --- AAAA
# INFO --- BBBB
# WARNING --- CCCC

%(name)s Logger的名字
%(levelname)s 文本形式的日志级别
%(message)s 用户输出的消息
%(asctime)s 字符串形式的当前时间。默认格式是 “2003-07-08 16:49:45,896”。逗号后面的是毫秒
%(levelno)s 数字形式的日志级别
%(pathname)s 调用日志输出函数的模块的完整路径名，可能没有
%(filename)s 调用日志输出函数的模块的文件名
%(module)s 调用日志输出函数的模块名
%(funcName)s 调用日志输出函数的函数名
%(lineno)d 调用日志输出函数的语句所在的代码行
%(created)f 当前时间，用UNIX标准的表示时间的浮点数表示
%(relativeCreated)d 输出日志信息时的，自Logger创建以来的毫秒数
%(thread)d 线程ID。可能没有
%(threadName)s 线程名。可能没有
%(process)d 进程ID。可能没有

在消息中显示日期/时间

在格式字符串中放置'%(asctime)s'
控制时间格式 : datefmt 参数

import logging

logging.basicConfig(format='%(levelname)s --- %(asctime)s --- %(message)s',level=logging.DEBUG)

logging.debug('AAAA')
logging.info('BBBB')
logging.warning('CCCC')
# DEBUG --- 2019-07-28 12:09:48,528 --- AAAA
# INFO --- 2019-07-28 12:09:48,528 --- BBBB
# WARNING --- 2019-07-28 12:09:48,528 --- CCCC

import logging

logging.basicConfig(format='%(levelname)s --- %(asctime)s --- %(message)s',datefmt='%m/%d/%Y %I:%M:%S %p' ,level=logging.DEBUG)

logging.debug('AAAA')
logging.info('BBBB')
logging.warning('CCCC')
# DEBUG --- 07/28/2019 12:11:40 PM --- AAAA
# INFO --- 07/28/2019 12:11:40 PM --- BBBB
# WARNING --- 07/28/2019 12:11:40 PM --- CCCC

进阶教程

日志记录流程的整体框架

1564305056644

Logger：即 Logger Main Class，是我们进行日志记录时创建的对象，我们可以调用它的方法传入日志模板和信息，来生成一条条日志记录，称作 Log Record。
Log Record：就代指生成的一条条日志记录。
Handler：即用来处理日志记录的类，它可以将 Log Record 输出到我们指定的日志位置和存储形式等，如我们可以指定将日志通过 FTP 协议记录到远程的服务器上，Handler 就会帮我们完成这些事情。
Formatter：实际上生成的 Log Record 也是一个个对象，那么我们想要把它们保存成一条条我们想要的日志文本的话，就需要有一个格式化的过程，那么这个过程就由 Formatter 来完成，返回的就是日志字符串，然后传回给 Handler 来处理。
Filter：另外保存日志的时候我们可能不需要全部保存，我们可能只需要保存我们想要的部分就可以了，所以保存前还需要进行一下过滤，留下我们想要的日志，如只保存某个级别的日志，或只保存包含某个关键字的日志等，那么这个过滤过程就交给 Filter 来完成。
Parent Handler：Handler 之间可以存在分层关系，以使得不同 Handler 之间共享相同功能的代码

日志记录的相关用法

总的来说 logging 模块相比 print 有这么几个优点：

可以在 logging 模块中设置日志等级，在不同的版本（如开发环境、生产环境）上通过设置不同的输出等级来记录对应的日志，非常灵活。
print 的输出信息都会输出到标准输出流中，而 logging 模块就更加灵活，可以设置输出到任意位置，如写入文件、写入远程服务器等。
logging 模块具有灵活的配置和格式化功能，如配置输出当前模块信息、运行时间等，相比 print 的字符串格式化更加方便易用。

import logging

 
logging.basicConfig(level=logging.INFO, format='%(asctime)s - %(name)s - %(levelname)s - %(message)s')
# 声明了一个 Logger 对象，它就是日志输出的主类
# 传入了模块的名称，这里直接使用 __name__ 来代替了，就是模块的名称
logger = logging.getLogger(__name__)
 
logger.info('This is a log info')
logger.debug('Debugging')
logger.warning('Warning exists')
logger.info('Finish')
# 2019-07-28 14:51:35,360 - __main__ - INFO - This is a log info
# 2019-07-28 14:51:35,360 - __main__ - WARNING - Warning exists
# 2019-07-28 14:51:35,360 - __main__ - INFO - Finish

basicConfig 的参数

filename：即日志输出的文件名，如果指定了这个信息之后，实际上会启用 FileHandler，而不再是 StreamHandler，这样日志信息便会输出到文件中了。
filemode：这个是指定日志文件的写入方式，有两种形式，一种是 w，一种是 a，分别代表清除后写入和追加写入。
format：指定日志信息的输出格式
datefmt：指定时间的输出格式。
style：如果 format 参数指定了，这个参数就可以指定格式化时的占位符风格，如 %、{、$ 等。
level：指定日志输出的类别，程序会输出大于等于此级别的信息。
stream：在没有指定 filename 的时候会默认使用 StreamHandler，这时 stream 可以指定初始化的文件流。
handlers：可以指定日志处理时所使用的 Handlers，必须是可迭代的。

Handler

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')

可以看出设置的流程为:

创建一个logger类

为logger类设置日志等级

创建一个headler

创建一个formatter

将formatter添加到headler

将这个headler添加到logger类上

logging 模块提供的 Handler 有：

StreamHandler：
logging.StreamHandler；日志输出到流，可以是 sys.stderr，sys.stdout 或者文件。
FileHandler：
logging.FileHandler；日志输出到文件。
BaseRotatingHandler：
logging.handlers.BaseRotatingHandler；基本的日志回滚方式。
RotatingHandler：
logging.handlers.RotatingHandler；日志回滚方式，支持日志文件最大数量和日志文件回滚。
TimeRotatingHandler：
logging.handlers.TimeRotatingHandler；日志回滚方式，在一定时间区域内回滚日志文件。
SocketHandler：
logging.handlers.SocketHandler；远程输出日志到TCP/IP sockets。
DatagramHandler：
logging.handlers.DatagramHandler；远程输出日志到UDP sockets。
SMTPHandler：
logging.handlers.SMTPHandler；远程输出日志到邮件地址。
SysLogHandler：
logging.handlers.SysLogHandler；日志输出到syslog。
NTEventLogHandler：
logging.handlers.NTEventLogHandler；远程输出日志到Windows NT/2000/XP的事件日志。
MemoryHandler：
logging.handlers.MemoryHandler；日志输出到内存中的指定buffer。
HTTPHandler：
logging.handlers.HTTPHandler；通过”GET”或者”POST”远程输出到HTTP服务器。

所以,我们可以如下设置:

import sys
import logging
 
# 创建logger
logger = logging.getLogger(__name__)

# 创建两个headler
handler1 = logging.FileHandler('output.log')
handler2 = logging.StreamHandler(sys.stdout)

# 为两个headler设置日志等级
handler1.setLevel(level=logging.DEBUG)
handler2.setLevel(level=logging.INFO)

# 创建formatter
formatter = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s')

# 为两个headler设置formatter
handler1.setFormatter(formatter)
handler2.setFormatter(formatter)

# 将headler添加到logger上
logger.addHandler(handler1)
logger.addHandler(handler2)
 

logger.info('This is a log info')
logger.debug('Debugging')
logger.warning('Warning exists')
logger.info('Finish')

这样,日志就可以同时输出到标准流和文件上了

或者:

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:8001', 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')

Formatter

import logging
 
logger = logging.getLogger(__name__)
logger.setLevel(level=logging.WARN)
formatter = logging.Formatter(fmt='%(asctime)s - %(name)s - %(levelname)s - %(message)s', datefmt='%Y/%m/%d %H:%M:%S')
handler = logging.StreamHandler()
handler.setFormatter(formatter)
logger.addHandler(handler)
 
# Log
logger.debug('Debugging')
logger.critical('Critical Something')
logger.error('Error Occurred')
logger.warning('Warning exists')
logger.info('Finished')

捕获 Traceback

如果遇到错误，我们更希望报错时出现的详细 Traceback 信息，便于调试，利用 logging 模块我们可以非常方便地实现这个记录，我们用一个实例来感受一下：

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('output.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.info('Finished')

# 2019-07-28 15:15:33,913 - __main__ - INFO - Start
# 2019-07-28 15:15:33,913 - __main__ - WARNING - Something maybe fail.
# 2019-07-28 15:15:33,914 - __main__ - ERROR - Faild to get result
# Traceback (most recent call last):
#   File "D:\trainingfile\training1.py", line 23, in <module>
#     result = 10 / 0
# ZeroDivisionError: division by zero
# 2019-07-28 15:15:33,915 - __main__ - INFO - Finished

配置共享

logging 模块提供了父子模块共享配置的机制，会根据 Logger 的名称来自动加载父模块的配置。

logging模块保证在同一个python解释器内，多次调用logging.getLogger(‘log_name’)都会返回同一个logger实例，即使是在多个模块的情况下。

所以典型的多模块场景下使用logging的方式是==在main模块中配置logging，这个配置会作用于多个的子模块，然后在其他模块中直接通过getLogger获取Logger对象即可==。
获取方式是:
子模块mod.py：
1
logger = logging.getLogger('main.mod')
子子模块submod.py：
1
logger = logging.getLogger('main.mod.submod')

# 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()

# core.py
import logging
 
logger = logging.getLogger('main.core')
 
def run():
    logger.info('Core Info')
    logger.debug('Core Debug')
    logger.error('Core Error')

2019-07-28 15:20:59,638 - main - INFO - Main Info
2019-07-28 15:20:59,639 - main - ERROR - Main Error
2019-07-28 15:21:09,279 - main - INFO - Main Info
2019-07-28 15:21:09,279 - main - ERROR - Main Error
2019-07-28 15:21:09,279 - main.core - INFO - Core Info
2019-07-28 15:21:09,279 - main.core - ERROR - Core Error

logger = logging.getLogger('main.core') :
这里我们定义了 Logger 的名称为 main.core，注意这里开头是 main，即刚才我们在 main.py 里面的 Logger 的名称，这样 core.py 里面的 Logger 就会复用 main.py 里面的 Logger 配置，而不用再去配置一次了。

文件配置

首先我们定义一个 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
import logging
import core
import yaml
import logging.config
import os


def setup_logging(default_path='config.yaml', default_level=logging.INFO):
    path = default_path
    if os.path.exists(path):
        with 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()

# core.py
import logging
 
logger = logging.getLogger('main.core')
 
def run():
    logger.info('Core Info')
    logger.debug('Core Debug')
    logger.error('Core Error')

这里我们定义了一个 setup_logging() 方法，里面读取了 yaml 文件的配置，然后通过 dictConfig() 方法将配置项传给了 logging 模块进行全局初始化。

日志记录使用常见误区

在日志输出的时候经常我们会用到字符串拼接的形式，很多情况下我们可能会使用字符串的 format() 来构造一个字符串，但这其实并不是一个好的方法，因为还有更好的方法，下面我们对比两个例子：

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')

在进行异常处理的时候，通常我们会直接将异常进行字符串格式化，但其实可以直接指定一个参数将 traceback 打印出来，示例如下：

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')

如果我们直接使用字符串格式化的方法将错误输出的话，是不会包含 Traceback 信息的，

如果我们加上 exc_info 参数或者直接使用 exception() 方法打印的话，那就会输出 Traceback 信息了。