Python 内置模块之 logging

日志的级别和适用情况

级别	适用情况
DEBUG	详细信息，通常只在诊断问题时对其感兴趣
INFO	确认工作正常
WARNING	表示发生了意料之外的事或者在不远的将来会有问题（比如磁盘空间低）。软件依然正常工作
ERROR	由于一个更加严重的问题，软件不能执行某些功能
CRITICAL	严重的错误，表示程序可能不能继续运行

组件

logging 库提供了以下组件：

• 日志记录器(Logger)：日志记录器暴露应用程序代码可以直接使用的接口。
• 处理器(Handler)：处理器发送日志（由日志记录器创建）到对应的目的地。
• 过滤器(Filter)：过滤器筛选日志。
• 和格式化器(Formatter)：格式化器决定最终输出的日志的格式。

目的地

可以将信息记录到不同的目的地。目的地由处理器提供。在 logging 库中支持将信息记录到文件、HTTP GET/POST 地址、基于 SMTP 的 email等，详细见 Useful Handlers。如果自带的处理器类不能满足你的特定需求，你也可以自定义日志目的地。

日志记录默认是没有目的地（处理器）的。当你调用 logging 的 debug() 等函数时，它们会检查处理器是否设置了目的地；如果没有设置，它会自动调用 logging.basicConfig() 来设置。

basicConfig

logging.basicConfig 只有第一次设置才会生效，即第一次之后的设置不会覆盖第一次设置。

logging.basicConfig 默认情况下给 root logger 添加一个默认格式的、目的地为控制台的处理器。

import logging
root = logging.getLogger()
root.handlers
# []

logging.basicConfig()
root.handlers
# [<logging.StreamHandler object at 0x1010b68d0>]

logging模块有三种配置方式，一种是函数式的简单配置，一种是对象类的，还有一种是配置文件类型的

配置方式1：函数式简单配置

import logging


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

默认情况下Python的logging模块将日志打印到了标准输出中，且只显示了大于等于WARNING级别的日志，这说明默认的日志级别设置为WARNING，默认的日志格式为日志级别：Logger名称：用户输出消息。配置日志级别，日志格式，输出位置:

import logging  
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='/tmp/test.log',  
    filemode='w'
)  
  
logging.debug('debug message')  
logging.info('info message')  
logging.warning('warning message')  
logging.error('error message')  
logging.critical('critical message')

logging.basicConfig()可用参数有：

filename：用指定的文件名创建FiledHandler，这样日志会被存储在指定的文件中。
filemode：文件打开方式，在指定了filename时使用这个参数，默认值为“a”还可指定为“w”。
format：指定handler使用的日志显示格式。
datefmt：指定日期时间格式。
level：设置rootlogger（后边会讲解具体概念）的日志级别
stream：用指定的stream创建StreamHandler。可以指定输出到sys.stderr,sys.stdout或者文件(f=open(‘test.log’,’w’))，默认为sys.stderr。若同时列出了filename和stream两个参数，则stream参数会被忽略。

format参数中可能用到的格式化串：

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

配置方式2：logger对象配置

import logging


logger = logging.getLogger()
logger.setLevel(logging.DEBUG)

# 创建一个handler，用于写入日志文件
fh = logging.FileHandler('test.log',encoding='utf-8')

# 定义一个RotatingFileHandler(使用日志回滚时使用)，最多备份3个日志文件，每个日志文件最大1K   
rHandler = RotatingFileHandler("log.txt",maxBytes = 1*1024,backupCount = 3)

# 输出到控制台的handler
ch = logging.StreamHandler()

# 输出为空的handler
nullhandler = logging.NullHandler()                            

# 设置formatter格式
formatter = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s') 

fh.setLevel(logging.DEBUG)
fh.setFormatter(formatter)   # 把fh 和 格式 绑定
ch.setFormatter(formatter)
logger.addHandler(fh)        # logger对象可以添加多个fh和ch对象 
logger.addHandler(ch) 

logger.debug('logger debug message') 
logger.info('logger info message') 
logger.warning('logger warning message') 
logger.error('logger error message') 
logger.critical('logger critical message')

设置日志可以通过：logger.setLevel(logging.Debug)设置级别,当然，也可以通过fh.setLevel(logging.Debug)单对文件流设置某个级别。

注：如果通过fh.setLevel(logging.Debug)单对文件流设置某个级别，则需要先修改logging.getLogger()，即logging获取时的级别，因为 logging.getLogger('')(root logger)的默认日志级别是 WARNING 所以在设置fh.setLevel(logging.Debug)低于wraning时，会获取不到，需要先修改logger.setLevel(logging.INFO)

扩展传给syslogserver，邮箱

# 日志传送到syslog server  
syslog_handler = handlers.SysLogHandler(address=('192.168.168.1', 514))  
# 日志传送给邮箱  
mail_handler = handlers.SMTPHandler('192.168.168.1', 'winter@126.com', 'elly@163.com', 'subject')
# 邮件给多人
mail_handler = handlers.SMTPHandler('192.168.168.1', 'winter@126.com', （'elly@163.com', 'dxd@126.com'), 'subject')

配置方式3：logger的配置文件

上面这种方式需要创建各种对象，比如logger对象，fileHandler对象，ScreamHandler对象等等，比较麻烦，下面提供一种字典的方式，创建logger配置文件，这种才是工作中经常使用的实现日志功能的方法，真正的做到拿来即用（简单改改）。

import os
import logging.config


# 定义日志输出格式
log_format_standard = '[%(asctime)s][%(threadName)s:%(thread)d][task_id:%(name)s][%(filename)s:%(lineno)d][%(levelname)s][%(message)s]'   
log_format_simple = '[%(levelname)s][%(asctime)s][%(filename)s:%(lineno)d]%(message)s'
id_simple_format = '[%(levelname)s][%(asctime)s] %(message)s'

logfile_dir = os.path.dirname(os.path.abspath(__file__)) 
logfile_name = 'info.log'

# 如果不存在定义的日志目录就创建一个
if not os.path.isdir(logfile_dir):
    os.mkdir(logfile_dir)

logfile_path = os.path.join(logfile_dir, logfile_name)   # log文件的全路径

# log配置字典
LOGGING_DIC = {
    'version': 1,
    'disable_existing_loggers': False,
    'formatters': {
        'standard': {'format': log_format_standard},
        'simple': {'format': log_format_simple},
    },
    'filters': {},
    'handlers': {
        'console': {        # 打印到终端的日志
            'level': 'DEBUG',
            'class': 'logging.StreamHandler',  # 打印到屏幕
            'formatter': 'simple'
        },
        'default': {        # 打印到文件的日志,收集info及以上的日志 
            'level': 'DEBUG',
            'class': 'logging.handlers.RotatingFileHandler',  # 保存到文件
            'formatter': 'standard',
            'filename': logfile_path,  # 日志文件
            'maxBytes': 1024*1024*5,   # 日志大小 5M
            'backupCount': 5,
            'encoding': 'utf-8',       # 日志文件的编码，再也不用担心中文log乱码了
        },
    },
    'loggers': {            # logging.getLogger(__name__)拿到的logger配置
        '': {
            'handlers': ['default', 'console'],  # 把上面定义的两个handler都加上，即log数据既写入文件又打印到屏幕
            'level': 'DEBUG',
            'propagate': True,  # 向上（更高level的logger）传递
        },
    },
}


def load_my_logging_cfg():
    logging.config.dictConfig(LOGGING_DIC)  # 导入上面定义的logging配置
    logger = logging.getLogger(__name__)    # 生成一个log实例
    logger.info('It works!')                # 记录该文件的运行状态


if __name__ == '__main__':
    load_my_logging_cfg()

注意注意注意：

1. 有了上述方式我们的好处是：所有与logging模块有关的配置都写到字典中就可以了，更加清晰，方便管理
2. 我们需要解决的问题是：
   1. 字典加载配置：logging.config.dictConfig(settings.LOGGING_DIC)
   2. 拿到logger对象来产生日志，logger对象都是配置到字典的loggers 键对应的子字典中的，按照我们对logging模块的理解，要想获取某个东西都是通过名字，也就是key来获取的，于是我们要获取不同的logger对象就是
   3. logger=logging.getLogger('loggers子字典的key名')
   4. 但问题是：如果我们想要不同logger名的logger对象都共用一段配置，那么肯定不能在loggers子字典中定义n个key 
3. loggers子字典匹配规则
   1. 以 . 为分割，从前往后匹配子字典中的key值。
   2. 例：如要匹配 app.utils，则会匹配子字典的key值为（app 和 app.utils，两者都会匹配）

'loggers': {    
        'l1': {
            'handlers': ['default', 'console'],  #
            'level': 'DEBUG',
            'propagate': True,  # 向上（更高level的logger）传递
        },
        'l2: {
            'handlers': ['default', 'console' ], 
            'level': 'DEBUG',
            'propagate': False,  # 向上（更高level的logger）传递
        },
        'l3': {
            'handlers': ['default', 'console'],  #
            'level': 'DEBUG',
            'propagate': True,  # 向上（更高level的logger）传递
        },

}

    
# 我们的解决方式是，定义一个空的key
    'loggers': {
        '': {
            'handlers': ['default', 'console'], 
            'level': 'DEBUG',
            'propagate': True, 
        },

}

# 这样我们再取logger对象时logging.getLogger(__name__)，不同的文件__name__不同，这保证了打印日志时标识信息不同，但是拿着该名字去loggers里找key名时却发现找不到，于是默认使用key=''的配置

其他通过yaml 和 模块配置 捕获异常等 可参考

• https://www.cnblogs.com/liujiacai/p/7804848.html
• https://www.cnblogs.com/louis-w/p/8567434.html

[BUG] python实例化N次类，调用类函数log会输出N遍的bug 解决办法

最近再写DOU用例时，采用的是 unittest测试框架，就涉及到将其它所有模块需要全部在一个 .py文件中进行实例化，然后再运行时发现在控制台中同一个日志信息会打印多次（实例化几次，同一消息就会打印几次），现象如下：

在common.py 中找到 log 的输出方法，代码如下：

def get_logger(ch_leval='INFO'):
    logger = logging.getLogger()
    logger.setLevel(logging.DEBUG)
    l_format = '[%(asctime)s][%(process)s][%(levelname)s][%(message)s]'
    formatter = logging.Formatter(l_format)
    
    fh = logging.FileHandler('xu.log',encoding='utf-8')
    fh.setLevel(logging.ERROR)
    fh.setFormatter(formatter)
    logger.addHandler(fh)

    ch = logging.StreamHandler()
    ch.setLevel(getattr(logging,ch_leval)) 
    ch.setFormatter(formatter)
    logger.addHandler(ch)

我们每次在实例化 get_loger() 方法时，都会添加一次 handlers，logger.handlers 实例上是一个列表，这就会导致我们多次进行实例化，这个logger.handlers就会把每次的 handler 添加进来（即使两个名字相同）。

所以这里有以下几个解决办法：

1. 每次创建不同name的logger，每次都是新logger，不会有添加多个handler的问题。（不解决问题）
2. 像上面一样每次记录完日志之后，调用removeHandler()把这个logger里的handler移除掉。（需要在使用完成之后移除）
3. 在log方法里做判断，如果这个logger已有handler，则不再添加handler。
4. 与方法2一样，不过把用pop把logger的handler列表中的handler移除。

办法3的代码示例：

def get_logger(ch_leval='INFO'):
    logger = logging.getLogger()
    logger.setLevel(logging.DEBUG)
    if not logger.handlers:
        l_format = '[%(asctime)s][%(process)s][%(levelname)s][%(message)s]'
        formatter = logging.Formatter(l_format)
    
        fh = logging.FileHandler('xu.log',encoding='utf-8')
        fh.setLevel(logging.ERROR)
        fh.setFormatter(formatter)
        logger.addHandler(fh)

        ch = logging.StreamHandler()
        ch.setLevel(getattr(logging,ch_leval)) 
        ch.setFormatter(formatter)
        logger.addHandler(ch)

Logger.error or Logger.exception

logger.exception(msg,_args)等价于logger.error(msg,exc_info = True,_args)，

Logger.exception() creates a log message similar to Logger.error(). The difference is that Logger.exception() dumps a stack trace along with it. Call this method only from an exception handler.

Exception handler 的意思是要在 except 中调用：

try:
    1 / 0
except:
    logging.exception('msg')
    
ERROR:root:msg
Traceback (most recent call last):
  File "<ipython-input-9-63e73c36224b>", line 2, in <module>
    1 / 0
ZeroDivisionError: integer division or modulo by zero

如果不在 except 中调用会 raise Empty

logging.exception('msg')
ERROR:root:msg
Traceback (most recent call last):
  File "/Applications/PyCharm.app/Contents/helpers/pydev/pydevconsole.py", line 198, in process_exec_queue
    code_fragment = interpreter.exec_queue.get(block=True, timeout=1/20.) # 20 calls/second
  File "/System/Library/Frameworks/Python.framework/Versions/2.7/lib/python2.7/Queue.py", line 176, in get
    raise Empty
Empty

不打印 requests 的日志

最近写的代码基本都用到了python的标准日志模块logging，但发现在使用requests模块和elasticsearch时，即使自己没有打印相关日志，也会自动生成请求过程日志，示例如下：

Starting new HTTP connection (1): example.com
http://example.com:80 "GET / HTTP/1.1" 200 606

 上面这种日志我们是不需要的，如果这种日志和我们自己打的日志混合在一块儿，日志文件将变得难以查看，对后面的问题排查带来很多不便，因此我们需要禁用掉这种默认的日志打印，方法如下：

logging.getLogger("requests").setLevel(logging.WARNING)    # requests 模块
logging.getLogger("urllib3").setLevel(logging.WARNING)     # urllib3 模块
logging.getLogger("elasticsearch").setLevel(logging.WARNING) # elasticsearch 模块
logging.getLogger("werkzeug")   # werkzeug 模块
logging.getLogger("app")        # flask 模块