Python3之logging模块浅析
Python3之logging模块浅析
很多程序都有记录日志的需求,并且日志中包含的信息即有正常的程序访问日志,还可能有错误、警告等信息输出,python的logging模块提供了标准的日志接口,你可以通过它存储各种格式的日志,logging的日志可以分为 debug(), info(), warning(), error() and critical()5个级别,下面我们看一下怎么用。
简单用法
- 在控制台进行显示 logging.info('xxxxx') 有以下五个级别:debug、info、warning、error、critical
import logging
logging.warning("warning:user/passwd is invalid")
logging.critical("critical:server is down")
- 在日志中输出 logging.basicConfig(),日志级别同样是有五个
import logging
logging.basicConfig(filename='access.log',level=logging.INFO,format='%(asctime)s %(message)s',
datefmt='%m/%d/%Y %I:%M:%S %p')
#basicConfig 方法对日志进本信息进行配置,文件名、日志级别、输出格式等,但必须以key-value形式使用
logging.debug('This message should go to the log file?') # 由于上面已经将日志级别设置为INFO,故低于INFO的不会被打印
logging.info('So should this')
logging.warning('And this, too')
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 | 用户输出的消息 |
日志与控制台同时输出
Python 使用logging模块记录日志涉及四个主要类,使用官方文档中的概括最为合适:
- logger提供了应用程序可以直接使用的接口;
- handler将(logger创建的)日志记录发送到合适的目的输出;
- filter提供了细度设备来决定输出哪条日志记录;
- formatter决定日志记录的最终输出格式
一个同时输出到屏幕、文件的完成例子
可按以下步骤进行创建
- 生成logger对象
- 生成handler 对象
- 把handler 对象绑定到logger对象
- 生成formatter 对象
- 将formatter对象绑定到handler对象
实现代码如下:
# -*- coding:utf-8 -*-
import logging
def logger(log_obj):
logger = logging.getLogger(log_obj)
logger.setLevel(logging.INFO)
console_handle = logging.StreamHandler()
log_file = "access.log"
file_handle = logging.FileHandler(log_file)
file_handle.setLevel(logging.WARNING)
formatter = logging.Formatter(
'%(asctime)s - %(name)s - %(levelname)s - %(message)s')
console_handle.setFormatter(formatter)
file_handle.setFormatter(formatter)
logger.addHandler(console_handle)
logger.addHandler(file_handle)
return logger
日志文件截取
- 按照大小截取
logging.handlers.RotatingFileHandler()
当文件达到一定大小之后,它会自动将当前日志文件改名,然后创建 一个新的同名日志文件继续输出。比如日志文件是chat.log。当chat.log达到指定的大小之后,RotatingFileHandler自动把 文件改名为chat.log.1。不过,如果chat.log.1已经存在,会先把chat.log.1重命名为chat.log.2。。。最后重新创建 chat.log,继续输出日志信息。它的函数是:
RotatingFileHandler( filename[, mode[, maxBytes[, backupCount]]])
其中filename和mode两个参数和FileHandler一样。
maxBytes用于指定日志文件的最大文件大小。如果maxBytes为0,意味着日志文件可以无限大,这时上面描述的重命名过程就不会发生。
backupCount用于指定保留的备份文件的个数。比如,如果指定为2,当上面描述的重命名过程发生时,原有的chat.log.2并不会被更名,而是被删除。
- 按照时间截取
logging.handlers.TimedRotatingFileHandler()
这个Handler和RotatingFileHandler类似,不过,它没有通过判断文件大小来决定何时重新创建日志文件,而是间隔一定时间就 自动创建新的日志文件。重命名的过程与RotatingFileHandler类似,不过新的文件不是附加数字,而是当前时间。它的函数是:
TimedRotatingFileHandler( filename [,when [,interval [,backupCount]]])
其中filename参数和backupCount参数和RotatingFileHandler具有相同的意义。
interval是时间间隔。
when参数是一个字符串。表示时间间隔的单位,不区分大小写。它有以下取值:
S 秒
M 分
H 小时
D 天
W 每星期(interval==0时代表星期一)
midnight 每天凌晨
- 代码实现如下:
# -*- coding:utf-8 -*-
import logging
from logging import handlers
logger = logging.getLogger(__name__)
log_file_size = "sizelog.log"
log_file_time = "timelog.log"
file_handler_size = logging.handlers.RotatingFileHandler(filename=log_file_size,maxBytes=10,backupCount=3)
file_handler_time = logging.handlers.TimedRotatingFileHandler(filename=log_file_time,when="S",interval=5,backupCount=3)
formatter = logging.Formatter('%(asctime)s %(module)s:%(lineno)d %(message)s')
file_handler_size.setFormatter(formatter)
file_handler_time.setFormatter(formatter)
logger.addHandler(file_handler_size)
logger.addHandler(file_handler_time)
logger.warning("test1")
logger.warning("test12")
logger.warning("test13")
logger.warning("test14")
日志重复打印问题解决
- 以下内容根据同学分享内容进行整理
在python中函数编程可以大大的减少重复代码量,在打印日志时,为避免重复造轮子,可使用创建log函数进行调用。
# -*- coding:utf-8 -*-
import logging
def my_logger(log_obj):
print(logging._handlerList)
logger = logging.getLogger(log_obj)
logger.setLevel(logging.INFO)
console_handle = logging.StreamHandler()
formatter = logging.Formatter(
'%(asctime)s - %(name)s - %(levelname)s - %(message)s ')
console_handle.setFormatter(formatter)
logger.addHandler(console_handle)
return logger
if __name__ == '__main__':
my_logger('access').error('say 1 ')
my_logger('access').error('say 2 ')
my_logger('access').error('say 3 ')
恩就这样定义好了一个log 函数,那我们来执行一下:
2018-06-24 13:25:54,411 - access.log - ERROR - say 1
2018-06-24 13:25:54,412 - access.log - ERROR - say 2
2018-06-24 13:25:54,412 - access.log - ERROR - say 2
2018-06-24 13:25:54,412 - access.log - ERROR - say 3
2018-06-24 13:25:54,412 - access.log - ERROR - say 3
2018-06-24 13:25:54,412 - access.log - ERROR - say 3
What's the fuck!为什么日志输出依次递增!
问题分析
实际上logger = logging.getLogger(log_obj)
在执行时,没有每次生成一个新的logger,而是先检查内存中是否存在一个叫做‘log_obj’的logger对象,存在则取出,不存在则新建。
- 实例化的logger对象具有‘handlers’这样一个属性来存储,我们打印看看存储的是什么信息
# -*- coding:utf-8 -*-
import logging
def my_logger(log_obj):
logger = logging.getLogger(log_obj)
print(logger.handlers)
logger.setLevel(logging.INFO)
console_handle = logging.StreamHandler()
formatter = logging.Formatter(
'%(asctime)s - %(name)s - %(levelname)s - %(message)s ')
console_handle.setFormatter(formatter)
logger.addHandler(console_handle)
return logger
if __name__ == '__main__':
my_logger('access').error('say 1 ')
my_logger('access').error('say 2 ')
my_logger('access').error('say 3 ')
[]
2018-06-24 13:44:47,239 - access.log - ERROR - say 1
[<StreamHandler <stderr> (NOTSET)>]
2018-06-24 13:45:22,597 - access.log - ERROR - say 2
2018-06-24 13:45:22,597 - access.log - ERROR - say 2
[<StreamHandler <stderr> (NOTSET)>, <StreamHandler <stderr> (NOTSET)>]
2018-06-24 13:45:32,877 - access.log - ERROR - say 3
2018-06-24 13:45:32,877 - access.log - ERROR - say 3
2018-06-24 13:45:32,877 - access.log - ERROR - say 3
从结果中可以看出:
logger.handlers
最初是一个空列表,执行logger.addHandler(console_handle)
添加一个StreamHandler
,输出一条日志- 在第二次被调用时,
logger.handlers
已经存在一个StreamHandler
,再次执行logger.addHandler(console_handle)
就会再次添加一个StreamHandler
,此时的logger有两个个StreamHandler
,输出两条重复的日志 - 在第三次被调用时,
logger.handlers
已经存在两个StreamHandler
,再次执行logger.addHandler(console_handle)
就会再次添加一个,此时的logger有三个StreamHandler
,输出三条重复的日志
解决方案
1.使用不同的日志对象
# -*- coding:utf-8 -*-
import logging
def my_logger(log_obj):
logger = logging.getLogger(log_obj)
print(logger.handlers)
logger.setLevel(logging.INFO)
console_handle = logging.StreamHandler()
formatter = logging.Formatter(
'%(asctime)s - %(name)s - %(levelname)s - %(message)s ')
console_handle.setFormatter(formatter)
logger.addHandler(console_handle)
return logger
if __name__ == '__main__':
my_logger('access1').error('say 1 ')
my_logger('access2').error('say 2 ')
my_logger('access3').error('say 3 ')
运行结果:
2018-06-24 13:51:33,084 - access1 - ERROR - say 1
2018-06-24 13:51:33,084 - access2 - ERROR - say 2
2018-06-24 13:51:33,085 - access3 - ERROR - say 3
2.及时清理(logger.handlers.clear)
# -*- coding:utf-8 -*-
import logging
def my_logger(log_obj):
logger = logging.getLogger(log_obj)
logger.handlers.clear()
#print(logger.handlers)
logger.setLevel(logging.INFO)
console_handle = logging.StreamHandler()
formatter = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s ')
console_handle.setFormatter(formatter)
logger.addHandler(console_handle)
return logger
if __name__ == '__main__':
my_logger('access').error('say 1 ')
my_logger('access').error('say 2 ')
my_logger('access').error('say 3 ')
运行结果如下:
2018-06-24 13:56:38,357 - access - ERROR - say 1
2018-06-24 13:56:38,358 - access - ERROR - say 2
2018-06-24 13:56:38,358 - access - ERROR - say 3
还有一种通过清理handler的方法但是兼容性较差
# 这种写法下的可以使用removeHandler方法或logger.handlers.pop()(logger.handlers.clear也可以使用在这种写法的函数内)
# -*- coding:utf-8 -*-
import logging
def my_logger(log_obj, msg):
logger = logging.getLogger(log_obj)
#print(logger.handlers)
logger.setLevel(logging.INFO)
console_handle = logging.StreamHandler()
formatter = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s ')
console_handle.setFormatter(formatter)
logger.addHandler(console_handle)
logger.error(msg)
logger.removeHandler(console_handle)
return logger
if __name__ == '__main__':
my_logger('access', 'say 1')
my_logger('access', 'say 2')
my_logger('access', 'say 3')
运行结果:
2018-06-24 14:02:08,390 - access - ERROR - say 1
2018-06-24 14:02:08,390 - access - ERROR - say 2
2018-06-24 14:02:08,390 - access - ERROR - say 3
3.使用前先判断是否有相同的handler对象
# -*- coding:utf-8 -*-
import logging
def my_logger(log_obj):
logger = logging.getLogger(log_obj)
logger.setLevel(logging.INFO)
# 判断logger是否已经添加过handler,是则直接返回logger对象,否则执行handler设定以及addHandler(console_handle)
if not logger.handlers:
console_handle = logging.StreamHandler()
formatter = logging.Formatter(
'%(asctime)s - %(name)s - %(levelname)s - %(message)s ')
console_handle.setFormatter(formatter)
logger.addHandler(console_handle)
return logger
if __name__ == '__main__':
my_logger('access').error('say 1')
my_logger('access').error('say 2')
my_logger('access').error('say 3')
总结:
第一次遇到这个问题的时候,没有找到原因,使用了创建多个日志对象的方法解决了问题,现在通过同学的分享已经搞清楚日志重复的原因:多次增加了相同的handler对象。
以后定要多积累,多请教。
参考内容: