浅谈logging模块
2019-04-22 本文已影响0人
oo的布丁
最近遇到了个头疼的问题，python的logging进程安全问题，借着这个机会，彻底把logging模块研究了一遍，分享一下心得。
首先介绍一下logging的几个组件，介绍之前先把配置文件放出来，下面会详细介绍：
LOGGING = {
"version": 1,
"disable_existing_loggers": False,
"formatters": {
"simple": {
# 简单的输出模式
'format': '%(asctime)s [%(name)s:%(lineno)d] [%(levelname)s]- %(message)s'
},
'standard': {
# 较为复杂的输出模式，可以进行自定义
'format': '%(asctime)s [%(threadName)s:%(thread)d] [%(name)s:%(lineno)d] [%(levelname)s]- %(message)s'
},
},
"handlers": {
# 输出到控制台的handler
"debug": {
# 定义输出流的类
"class": "logging.StreamHandler",
# handler等级，如果实际执行等级高于此等级，则不触发handler
"level": "DEBUG",
# 输出的日志格式
"formatter": "simple",
# 流调用系统输出
"stream": "ext://sys.stdout"
},
# 写入到文件的hanler，写入等级为info，命名为request是为了专门记录一些网络请求日志
"request": {
# 定义写入文件的日志类，此类为按时间分割日志类，还有一些按日志大小分割日志的类等
"class": "mlogging.TimedRotatingFileHandler_MP",
# 日志等级
"level": "INFO",
# 日志写入格式，因为要写入到文件后期可能会debug用，所以用了较为详细的standard日志格式
"formatter": "standard",
# 要写入的文件名
"filename": "./request.log",
# 分割单位，D日，H小时，M分钟，W星期，一般是以小时或天为单位
# 比如文件名为test.log，到凌晨0点的时候会自动分离出test.log.yyyy-mm-dd
"when": 'D',
"encoding": "utf8"
},
# 写入到文件的hanler，写入等级为info
"info": {
# 不再赘述，详细见request logger
"class": "mlogging.TimedRotatingFileHandler_MP",
"level": "INFO",
"formatter": "standard",
"filename": "./info.log"),
"when": 'D',
"encoding": "utf8"
},
# 写入到文件的hanler，写入等级为warning
"warning": {
# 不再赘述，详细见request logger
"class": "mlogging.TimedRotatingFileHandler_MP",
"level": "WARNING",
"formatter": "standard",
"filename": "./warning.log"),
"when": 'D',
"encoding": "utf8"
},
# 写入到文件的hanler，写入等级为error
"error": {
# 不再赘述，详细见request logger
"class": "mlogging.TimedRotatingFileHandler_MP",
"level": "ERROR",
"formatter": "standard",
"filename": "./error.log"),
"when": 'D',
"encoding": "utf8"
},
# 写入到文件的hanler，写入等级为critical（一般有重大错误的时候才会用到此类打印）
"critical": {
# 不再赘述，详细见request logger
"class": "mlogging.TimedRotatingFileHandler_MP",
"level": "CRITICAL",
"formatter": "standard",
"filename": "./critical.log"),
"when": 'D',
"encoding": "utf8"
},
},
"loggers": {
# logger名字
"debug_logger": {
# logger集成的handler
'handlers': ['debug'],
# logger等级，如果实际执行等级，高于此等级，则不触发此logger，logger中所有的handler均不会被触发
'level': "DEBUG",
# 是否继承root日志，如果继承，root的handler会加入到当前logger的handlers中
'propagate': False
},
# 不再赘述，详见debug_logger
"request_logger": {
'handlers': ['debug', 'request'],
'level': "INFO",
'propagate': False
},
# 不再赘述，详见debug_logger
"info_logger": {
'handlers': ['debug', 'info'],
'level': "INFO",
'propagate': False
},
# 不再赘述，详见debug_logger
"warning_logger": {
'handlers': ['debug', 'warning'],
'level': "WARNING",
'propagate': False
},
# 不再赘述，详见debug_logger
"error_logger": {
'handlers': ['debug', 'error'],
'level': "ERROR",
'propagate': False
},
# 不再赘述，详见debug_logger
"critical_logger": {
'handlers': ['debug', 'critical'],
'level': "CRITICAL",
'propagate': False
},
},
# 基础logger，当不指定logger名称时，默认选择此logger
"root": {
'handlers': ['info'],
'level': "DEBUG",
'propagate': False
}
}
# 用LOGGING配置logging
logging.config.dictConfig(LOGGING)
# 获取名为warning_logger的logger
logger = logging.getLogger('warning_logger')
# 打印各种日志
logger.debug('debug log')
logger.request('request log')
logger.info('info log')
logger.warning('warning log')
logger.error('error log')
logger.critical('critical log')
看完上面配置，注释多如狗，相信不用讲也能理解的差不多，不过还是分别讲讲。
logging分为3个组件，分别是：formater，handler和logger（配置文件中的version和disable_existing_loggers一般都是写死的，不用管），这三者的关系是这样的，logger负责调用handler（一个logger可以绑定多个handler），handler的打印或写入的内容则依赖于formater（一个handler只能对应一个formater），举个例子：
# 根据日志名从loggers中获取名为“warning_logger”的logger
logger = logging.getLogger('warning_logger')
# 获取的大概就是这一段，日志有2个handlers，分别是debug和warning
# "warning_logger": {
# 'handlers': ['debug', 'warning'],
# 'level': "WARNING",
# 'propagate': False
# }
# 打印warning日志，此时日志等级为warning，所有低于该等级的都会被打印，待会再讲什么是日志等级
logger.warning("warning log")
# 执行上面一段，会分别调用debug handler和warning handler，debug handler负责打印到控制台上，warning handler负责写入到./warning.log文件中。
以上就是一次简单的调用执行的过程，接下来分别细说下这几个模块。
1、formater
在平时写日志的过程中，很多固定的信息都是要记录的，比如日志时间，日志名称，日志等级，线程、进程信息等，每次都写不仅效率低，而且如果忘了写会导致日志内容的不一致，不容易解析，所以要为日志统一一下格式，正如下面配置文件中的，定义了名为simple的简单输出模式和名为standard复杂输出格式，当然还可以自定义其他格式：
"simple": {
# 简单的输出模式
'format': '%(asctime)s [%(name)s:%(lineno)d] [%(levelname)s]- %(message)s'
},
'standard': {
# 较为复杂的输出模式，可以进行自定义
'format': '%(asctime)s [%(threadName)s:%(thread)d] [%(name)s:%(lineno)d] [%(levelname)s]- %(message)s'
下面介绍下logging集成的输出格式中的一些参数，可以直接使用
asctime %(asctime)s 日志事件发生的时间，如：2003-07-08 16:49:45,896
created %(created)f 日志事件发生的时间--时间戳
msecs %(msecs)d 日志事件发生事件的毫秒部分
levelname %(levelname)s 日志等级
levelno %(levelno)s 日志级别的数字形式
name %(name)s 所使用的日志器名称，默认是'root'
message %(message)s 日志记录的文本内容
pathname %(pathname)s 调用日志记录函数的源码文件的全路径
filename %(filename)s pathname的文件名部分，包含文件后缀
module %(module)s filename的名称部分，不包含后缀
lineno %(lineno)d 调用日志记录函数的源代码所在的行号
funcName %(funcName)s 调用日志记录函数的函数名
process %(process)d 进程ID
processName %(processName)s 进程名称，Python 3.1新增
thread %(thread)d 线程ID
threadName %(thread)s 线程名称
2、handler
我目前了解到的，handler只做2件事情，第一是日志的打印，第二日志的写入和切分操作。
针对打印操作，handler可以调用logging.StreamHandler的类，stream配置为ext://sys.stdout，就可以完成打印到控制台。
针对写入操作，logging可以实现日志文件按大小或时间切割，按大小切割时，需要用到RotatingFileHandler类，并且需要制定文件切割的大小；按时间切割时则需要用到TimedRotatingFileHandler类，需要指定切割的时间点。本文以时间切割为例，需要配置when参数来指定切割时间点，具体配置如下：
“S”: Seconds
“M”: Minutes
“H”: Hours
“D”: Days
“W”: Week day (0=Monday)
“midnight”: Roll over at midnight
3、logger
其实没啥可说的，负责调用自己名下的handler。
最后，谈一下日志等级，包含：debug，info，warning，error，critical 5个等级，等级从左到右依次提升，就是说debug最低，critical最高。高等级的行为会触发低等级的logger或handler。
举个例子，等级为info的info_logger绑定了等级为debug的debug_handler和等级为warning的warning_handler，此时执行info_logger.info('info log')，此时执行等级为info，因自身等级不低于info，所以会被触发，此时依次触发名下的handler，首先是debug_handler，因为等级是deng低于info，所以debug_handler会执行，然后是warning_handler，因为等级高于info，所以不会触发。
再举个例子，比如执行info_logger.warning('info log')，此时执行等级为warning，高于info_logger的等级，所以info_logger不会被触发，尽管info_logger下有等级为warning的warning_handler，但是因为info_logger没有被触发，而其又依赖于info_logger存在，所以其也不会被触发。
本来还想写下如何处理logging的进程安全问题，不过突然觉得累了，简单说下。一个是mlogging模块，一个是ConcurrentLogHandler模块，都分别对此作了实现，或者可以改源码自己实现。大致原理都是借助fcntl模块给文件上锁解决的，亲测用python3的fcntl模块为文件加LOCK_EX锁，不仅其他python3的进程无法获取该文件的LOCK_EX锁，就连python2的进程也无法获取，猜测这个锁应该是系统级别的了。
嗯，先写这么多
更新一版最新的代码
import logging.config
import os
import sys
curr_path = os.path.abspath(os.path.dirname(__file__))
sys.path.append(curr_path)
'''
日志的配置参数，日志对象主要有3个子模块，分别为formater（输出格式），handler（日志操作类型），logger（日志名），要分别进行设置。
其中hadlers为日志的具体执行，依赖于formater和日志操作类型或一些属性，比如按大小分片还是时间分片，是写入还是打印到控制台。
logger负责调用handle，一个logger可以调用多个handler，比如logger.info调用了打印到控制台handler（logging.StreamHandler）
和写入到文件handler（mlogging.TimedRotatingFileHandler_MP），在没有指定logger名字的时候，即logger=logging.get_logger()的时候，
logger会自动选择名为root的logger
'''
# 当前兄弟目录
# log_root_path = os.path.join(str(os.path.abspath(__file__).rsplit('/', 1)[0]), 'logs')
LOGGING = {
"version": 1,
"disable_existing_loggers": False,
"formatters": {
"simple": {
# 简单的输出模式
'format': '%(asctime)s|%(name)s|file:%(filename)s|lineno:%(lineno)d|logger:%(name)s|%(levelname)s - %(message)s'
},
'standard': {
# 较为复杂的输出模式，可以进行自定义
'format': '%(asctime)s threadId:%(thread)d|processId:%(process)d:|file:%(filename)s|lineno:%(lineno)d|func:%(funcName)s|module:%(module)s|logger:%(name)s|%(levelname)s - %(message)s'
},
},
# 过滤器
"filters": {
'debug_filter': {
'()': 'log_filters.DebugFilter'
},
'info_filter': {
'()': 'log_filters.InfoFilter'
},
'warning_filter': {
'()': 'log_filters.WarningFilter'
},
'error_filter': {
'()': 'log_filters.ErrorFilter'
},
'critical_filter': {
'()': 'log_filters.CriticalFilter'
},
'no_debug_filter': {
'()': 'log_filters.NoDebugFilter'
}
},
"handlers": {
# 写入到文件的hanler，写入等级为info，命名为request是为了专门记录一些网络请求日志
"request": {
# 定义写入文件的日志类，此类为按时间分割日志类，还有一些按日志大小分割日志的类等
"class": "mlogging.TimedRotatingFileHandler_MP",
# 日志等级
"level": "INFO",
# 日志写入格式，因为要写入到文件后期可能会debug用，所以用了较为详细的standard日志格式
"formatter": "standard",
# 要写入的文件名
"filename": os.path.join(log_root_path, 'default', 'request.log'),
# 分割单位，D日，H小时，M分钟，W星期，一般是以小时或天为单位
# 比如文件名为test.log，到凌晨0点的时候会自动分离出test.log.yyyy-mm-dd
"when": 'D',
"encoding": "utf8",
},
# 输出到控制台的handler
"debug": {
# 定义输出流的类
"class": "logging.StreamHandler",
# handler等级，如果实际执行等级高于此等级，则不触发handler
"level": "DEBUG",
# 输出的日志格式
"formatter": "simple",
# 流调用系统输出
"stream": "ext://sys.stdout"
},
# 写入到文件的hanler，写入等级为info，命名为request是为了专门记录一些网络请求日志
"info": {
# 定义写入文件的日志类，此类为按时间分割日志类，还有一些按日志大小分割日志的类等
"class": "mlogging.TimedRotatingFileHandler_MP",
# 日志等级
"level": "INFO",
# 日志写入格式，因为要写入到文件后期可能会debug用，所以用了较为详细的standard日志格式
"formatter": "standard",
# 要写入的文件名
"filename": os.path.join(log_root_path, 'default', 'info.log'),
# 分割单位，D日，H小时，M分钟，W星期，一般是以小时或天为单位
# 比如文件名为test.log，到凌晨0点的时候会自动分离出test.log.yyyy-mm-dd
"when": 'D',
"encoding": "utf8",
"filters": ["info_filter"]
},
# 写入到文件的hanler，写入等级为warning
"warning": {
# 不再赘述，详细见request logger
"class": "mlogging.TimedRotatingFileHandler_MP",
"level": "WARNING",
"formatter": "standard",
"filename": os.path.join(log_root_path, 'default', 'warning.log'),
"when": 'D',
"encoding": "utf8",
"filters": ["info_filter"]
},
# 写入到文件的hanler，写入等级为error
"error": {
# 不再赘述，详细见request logger
"class": "mlogging.TimedRotatingFileHandler_MP",
"level": "ERROR",
"formatter": "standard",
"filename": os.path.join(log_root_path, 'default', 'error.log'),
"when": 'D',
"encoding": "utf8",
"filters": ["info_filter"]
},
# 写入到文件的hanler，写入等级为critical（一般有重大错误的时候才会用到此类打印）
"critical": {
# 不再赘述，详细见request logger
"class": "mlogging.TimedRotatingFileHandler_MP",
"level": "CRITICAL",
"formatter": "standard",
"filename": os.path.join(log_root_path, 'default', 'critical.log'),
"when": 'D',
"encoding": "utf8",
"filters": ["info_filter"]
},
},
"loggers": {
# logger名字
"my_logger": {
# logger集成的handler
'handlers': ['debug', 'info', 'warning', 'error', 'critical'],
# logger等级，如果实际执行等级，高于此等级，则不触发此logger，logger中所有的handler均不会被触发
'level': "DEBUG",
# 是否继承root日志，如果继承，root的handler会加入到当前logger的handlers中
'propagate': False
},
# logger名字
"my_request_logger": {
# logger集成的handler
'handlers': ['debug', 'request', 'warning', 'error', 'critical'],
# logger等级，如果实际执行等级，高于此等级，则不触发此logger，logger中所有的handler均不会被触发
'level': "DEBUG",
# 是否继承root日志，如果继承，root的handler会加入到当前logger的handlers中
'propagate': False
},
},
# 基础logger，当不指定logger名称时，默认选择此logger
"root": {
'handlers': ['info'],
'level': "DEBUG",
'propagate': False
}
}
# 定义日志类
class Logger:
# 单例模式存储对象
__instance = {}
__is_init = False
# 对于每个app name单例模式
def __new__(cls, app_name='default', *args, **kwargs):
if app_name not in cls.__instance:
cls.__instance[app_name] = super().__new__(cls)
return cls.__instance[app_name]
# 初始化logger，通过LOGGING配置logger
def __init__(self, app_name='default', is_debug=True):
if self.__is_init is True:
return
global log_root_path
log_file_dir = os.path.join(log_root_path, app_name)
print("app名为%s的日志被初始化了，日志会写入到：%s 文件夹下" % (app_name, log_file_dir))
self.__is_init = True
self.is_debug = is_debug
# 初始化logging配置参数
global LOGGING
# 默认路径为当前文件所在目录的兄弟目录logs下的default目录 ./logs/default
self.default_log_path = os.path.join(log_root_path, 'default')
# # 默认路径为当前文件所在目录的兄弟目录logs下的app_name目录 ./logs/${app_name}
self.log_root_path = os.path.join(log_root_path, app_name)
# 不存在就创建default目录
if not os.path.exists(self.log_root_path):
os.makedirs(self.log_root_path)
# 不存在就创建当前app_name对应的目录
if not os.path.exists(self.default_log_path):
os.makedirs(self.default_log_path)
# 日志名和日志等级的映射
log_levels = ['debug', 'info', 'warning', 'error', 'critical']
# 根据app_name动态更新LOGGING配置，为每个app_name创建文件夹，配置handler
for level in log_levels:
# handler名称，如default_debug
handler_name = '%s_%s' % (app_name, level)
if level == 'debug':
LOGGING['handlers'][handler_name] = self.get_console_handler_conf()
# 日志名称，如default_debug_logger
else:
# handler 对应文件名，如 logs/default/request.log
filename = os.path.join(self.log_root_path, (level + '.log'))
# 日志等级转大写
lev_up = level.upper()
LOGGING['handlers'][handler_name] = self.get_file_handler_conf(filename=filename, level=lev_up)
# 日志名称，如default_error_logger
# 单独初始化request handler
request_filename = os.path.join(self.log_root_path, 'request.log')
request_handler_name = '%s_request' % app_name
# 绑定request handler
LOGGING['handlers'][request_handler_name] = self.get_file_handler_conf(filename=request_filename, level="INFO")
# 添加app logger及app_request logger
logger_name = '%s_logger' % app_name
LOGGING['loggers'][logger_name] = self.get_logger_conf(app_name=app_name)
request_logger_name = '%s_request_logger' % app_name
LOGGING['loggers'][request_logger_name] = self.get_request_logger_conf(app_name=app_name)
# import json
# print(json.dumps(LOGGING, indent=2))
# 将LOGGING中的配置信息更新到logging中
logging.config.dictConfig(LOGGING)
# 这里之所以要分6种logger，而不是只写一种logger，是为了将不同等级的日志信息，写入到不同的文件中，方便后期的debug和统计
# 获取debug日志，用于只打印到控制台，不写入文件的日志，一般用于打印较长的sql，或是一大段json字符串
self.debug_logger = logging.getLogger("%s_debug_logger" % app_name)
# 获取request日志，一般用于记录请求日志，可以在用户开始访问和访问成功的时间点分别记录日志，可以统计访问的成功率
self.request_logger = logging.getLogger("%s_request_logger" % app_name)
# 获取info日志，也是最长用的一种日志，用于记录日常业务中的各种行为，是最灵活，使用最广泛的一种日志
self.info_logger = logging.getLogger("%s_info_logger" % app_name)
# 获取warning日志，一般用于有一些小错误或瑕疵，但不影响程序运行的行为的警告
self.warning_logger = logging.getLogger("%s_warning_logger" % app_name)
# 获取error日志，一般用于主动的错误提示，或者被动的捕获异常时的异常记录日志，常和try。。。except一起使用
self.error_logger = logging.getLogger("%s_error_logger" % app_name)
# 获取critical日志，用于重大异常，可能影响整体项目运行的异常
self.critical_logger = logging.getLogger("%s_critical_logger" % app_name)
# 控制台输出handler配置
def get_console_handler_conf(self):
console_handler_conf = {
# 定义输出流的类
"class": "logging.StreamHandler",
# handler等级，如果实际执行等级高于此等级，则不触发handler
"level": "DEBUG",
# 输出的日志格式
"formatter": "simple",
# 流调用系统输出
"stream": "ext://sys.stdout"
}
if self.is_debug:
console_handler_conf['filters'] = ['debug_filter']
else:
console_handler_conf['filters'] = ['no_debug_filter']
return console_handler_conf
@staticmethod
# 写入文件handler配置
def get_file_handler_conf(filename: str, level='INFO'):
file_handler_conf = {
# 定义写入文件的日志类，此类为按时间分割日志类，还有一些按日志大小分割日志的类等
"class": "mlogging.TimedRotatingFileHandler_MP",
# 日志等级
"level": "",
# 日志写入格式，因为要写入到文件后期可能会debug用，所以用了较为详细的standard日志格式
"formatter": "standard",
# 要写入的文件名
"filename": '',
# 分割单位，D日，H小时，M分钟，W星期，一般是以小时或天为单位
# 比如文件名为test.log，到凌晨0点的时候会自动分离出test.log.yyyy-mm-dd
"when": 'D',
"encoding": "utf8",
"filters": []
}
filters = ['%s_filter' % (level.lower())]
update_dict = {'filename': filename, 'level': level, 'filters': filters}
file_handler_conf.update(update_dict)
return file_handler_conf
@staticmethod
# logger 配置
def get_logger_conf(app_name='default'):
logger_conf = {
'handlers': [],
'level': "DEBUG",
'propagate': False
}
# 如果只是debug级别logger，只配置打印handler，不会记录到文件中
log_levels = ['debug', 'info', 'warning', 'error', 'critical']
logger_conf['handlers'] = ['%s_%s' % (app_name, level) for level in log_levels]
return logger_conf
@staticmethod
# request logger配置
def get_request_logger_conf(app_name='default'):
logger_conf = {
'handlers': [],
'level': "DEBUG",
'propagate': False
}
log_levels = ['debug', 'request', 'warning', 'error', 'critical']
logger_conf['handlers'] = ['%s_%s' % (app_name, level) for level in log_levels]
return logger_conf
# 获取日常logger
def get_logger(app_name: str, is_debug=True):
Logger(app_name, is_debug=is_debug)
logger_name = '%s_logger' % app_name
logger = logging.getLogger(logger_name)
return logger
# 获取request logger
def get_request_logger(app_name: str, is_debug=True):
Logger(app_name, is_debug=is_debug)
logger_name = '%s_request_logger' % app_name
logger = logging.getLogger(logger_name)
return logger
if __name__ == '__main__':
# 单例模式测试
logger = get_request_logger('lr_test', is_debug=True)
logger.debug('debug log')
logger.debug('debug log')
logger.debug('debug log')
filter代码：
import logging
class NoDebugFilter(logging.Filter):
def filter(self, record):
return False
class DebugFilter(logging.Filter):
def filter(self, record):
level = record.levelname.upper()
if level == 'DEBUG':
return True
return False
class InfoFilter(logging.Filter):
def filter(self, record):
level = record.levelname.upper()
if level in {'INFO', 'WARNING', 'ERROR'}:
return True
return False
class WarningFilter(logging.Filter):
def filter(self, record):
level = record.levelname.upper()
if level == 'WARNING':
return True
return False
class ErrorFilter(logging.Filter):
def filter(self, record):
level = record.levelname.upper()
if level == 'ERROR':
return True
return False
class CriticalFilter(logging.Filter):
def filter(self, record):
level = record.levelname.upper()
if level == 'CRITICAL':
return True
return False
