Python开发之日志记录模块:logging
Python开发之日志记录模块:logging
1 引言
最近在开发一个应用软件,为方便调试和后期维护,在代码中添加了日志,用的是Python内置的logging模块,看了许多博主的博文,颇有所得。不得不说,有许多博主大牛总结得确实很好。似乎我再写关于logging的博文有些多余,但不写总结又总觉得没掌握。那就写写吧,也方便日后回顾。 说说为什么需要添加日志? 为了调试和后期维护方便。也许在开发中没有太大体会,但是如果将软件部署到了生产环境中,一旦出现bug,没有日志,就很难对当时的情况进行追踪,有了日志,就可以根据日志尽可能的对当时的数据环境进行还原,方便debug。甚至,只要日志设计得足够合理,还可以用于后续业务数据分析等。2 日志等级
为什么需要对日志进行划分等级呢? 当我们出于开发时debug的目的使用日志时,我们自然是想尽可能详尽得记录日志,但是如果部署到生产环境中,这样做就可能因为大量的IO占用服务器资源,所以在生产环境中就只需要记录异常信息、错误情况等就好了。 所以,给日志设置等级,可以方便得、因地制宜控制日志输出。 这里只介绍Python的logging模块的日志等级(当然,其他日志系统的日志等级划分事实上也基本相同)。logging的日志等级包括5个:3 记录日志
logging模块提供两种方法记录日志: (1)通过logging模块提供的模块级函数记录日志; (2)通过logging模块提供的4大组件记录日志。
3.1 记录日志之logging模块级函数
在logging模块中,分别给出一个模块级别函数与上面说到的日志级别相对应,用于输出对应级别日志记录:import logging logging.debug('debug') logging.info('info') logging.warn('warn') logging.error('error') logging.critical('critical') logging.warn('Today is %s',datetime.date.today())运行结果如下: WARNING:root:warn ERROR:root:error CRITICAL:root:critical WARNING:root:Today is 2019-03-28 上面的函数都有*args, **kwargs这两个参数,所以这些函数可以接受任意位置参数和关键字参数,这些参数填充到第一个参数msg,最后一条日志输出中添加了当前日期就是利用了这个功能。 那为什么会只输出后面3条日志记录呢?上面说到过,logging就只会输出大于和等于设定的等级的日志记录,而logging的默认日志等级是WARNING,所以日志等级为DEBUG和INFO的两条记录都没有被输出。 如果想要输入日志等级为DEBUG和INFO的日志记录,就要对logging进行配置。logging也提供了一个模块级别的专用于配置logging的函数:
import logging logging.basicConfig(level=logging.DEBUG) # 设置日志等级 logging.debug('debug') logging.info('info') logging.warn('warn') logging.error('error') logging.critical('critical')运行结果如下: DEBUG:root:debug INFO:root:info WARNING:root:warn ERROR:root:error CRITICAL:root:critical 看,日志等级为DEBUG和INFO的两条记录也都得到了输出。 上面表格对logging.basicConfig函数的说明中指出,logging.basicConfig函数时一次性配置,什么意思呢?意思就是说,logging.basicConfig函数只在第一次运行(第一次对logging进行配置)时起作用,后面在此设置其他参数是不会生效的。通过代码证明一下:
import logging logging.basicConfig(level=logging.DEBUG) # 设置日志等级 logging.basicConfig(level=logging.INFO) # 重新设置日志等级 logging.debug('debug') logging.info('info') logging.warn('warn') logging.error('error') logging.critical('critical')运行结果: DEBUG:root:debug INFO:root:info WARNING:root:warn ERROR:root:error CRITICAL:root:critical 看到没,DEBUG级别日志记录还是输出了,证明重新运行logging.basicConfig函数设置日志级别没有生效。 另外需要注意的是,一定要在使用logging记录日志之前使用logging.basicConfig进行配置,否则,不会有任何输出。 我们再观察一下上面的程序输出,可以发现,每一条输出的结果里,不仅仅只有我们输出的字符串参数,还有其它的一些信息,例如日志等级,日志器名称(默认是root),分隔符(这里是冒号)等,这些都是logging默认给我配置好的,当然,我们也可以通过logging.basicConfig函数的各参数自定义logging的输出。
import logging fmt = '%(asctime)s , %(levelname)s , %(filename)s %(funcName)s line %(lineno)s , %(message)s' datefmt = '%Y-%m-%d %H:%M:%S %a' logging.basicConfig(level=logging.DEBUG, format=fmt, datefmt=datefmt, filename=".log") logging.debug('debug') logging.info('info') logging.warn('warn') logging.error('error') logging.critical('critical')运行上述代码后,控制台不会再有输出了,但当前目录下的.log文件会写入一下内容: 2019-03-28 16:34:08 Thu , DEBUG , log_test.py <module> line 8 , debug 2019-03-28 16:34:08 Thu , INFO , log_test.py <module> line 9 , info 2019-03-28 16:34:08 Thu , WARNING , log_test.py <module> line 10 , warn 2019-03-28 16:34:08 Thu , ERROR , log_test.py <module> line 11 , error 2019-03-28 16:34:08 Thu , CRITICAL , log_test.py <module> line 12 , critical
3.2 记录日志之logging四大组件
logging四大组件是logging日志记录的高级用法。四大组件包括Logger、Handelr、Filter、Formater,且都是以类的形式来使用。logging四大组件协同工作流如下如所示: 各组件功能如下:- logger.setLevel() :设置日志器处理日志信息的最低级别
- logger.addHandler():为该logger对象添加一个handler对象
- logger.removeHandler():为该logger对象添加移除一个handler对象
- logger.addFilter():为该logger对象添加一个filter对象
- logger.removeFilter():为该logger对象移除一个filter对象
- logger.debug(),logger.info(),logger.warning(),logger.error(),logger.critical():创建一个对应等级的日志记录
- handler.setLevel():设置handler处理的日志信息最低级别
- handler.setFormatter():为handler设置一个格式器对象
- handler.addFilter():为handler添加一个过滤器对象
- handler.removeFilter():为handler删除一个过滤器对象
import logging logger = logging.getLogger() logger.setLevel(logging.DEBUG) # 控制台输出 con_handler = logging.StreamHandler() con_handler.setLevel(logging.INFO) logger.addHandler(con_handler) # 输出到文件a.log file_a_handler = logging.FileHandler('./a.log', encoding='UTF-8') file_a_handler.setLevel(logging.DEBUG) logger.addHandler(file_a_handler) # 输出到文件b.log file_b_handler = logging.FileHandler('./b.log', encoding='UTF-8') file_b_handler.setLevel(logging.WARNING) logger.addHandler(file_b_handler) if __name__=='__main__': logger.debug('debug msg') logger.info('info msg') logger.warning('warn msg')运行上面代码后,控制台输出如下: info msg warn msg 文件a.log会写入一下内容: debug msg info msg warn msg 文件b.log会写入以下内容: warn msg 注意:在一个日志器中添加多个handler时要注意,最好通过logger.setLevel(logging.DEBUG)先设置一下logger本身的日志级别,如果某个handler的级别比logger的日志级别低,那么该handler的日志级别无效,handler会以logger的级别来处理。 (3)格式器:Formatter Formatter类实例用于配置日志记录的内容、结构等信息。可以通过以下三个参数进行配置:
- fmt:指定消息格式化字符串,如果不指定该参数则默认使用message的原始值
- datefmt:指定日期格式字符串,如果不指定该参数则默认使用"%Y-%m-%d %H:%M:%S"
- style:指定格式化占位符,可取值为 '%', '{'和 '$',如果不指定该参数则默认使用'%'
import logging logger = logging.getLogger(__name__) handler = logging.StreamHandler() logger.setLevel(logging.DEBUG) # 定义格式器,添加到处理器中 fmt = '%(asctime)s , %(levelname)s , %(filename)s %(funcName)s line %(lineno)s , %(message)s' datefmt = '%Y-%m-%d %H:%M:%S %a' log_fmt = logging.Formatter(fmt=fmt, datefmt=datefmt) handler.setFormatter(log_fmt) logger.addHandler(handler) logger.debug('debug msg') logger.info('info msg')控制台输出如下: 2019-03-29 19:36:03 Fri , DEBUG , log_test2.py <module> line 14 , debug msg 2019-03-29 19:36:03 Fri , INFO , log_test2.py <module> line 15 , info msg (4)过滤器:Filter 在我们已经知道的logging使用方法中,都是通过日志级别来控制日志是否输出,Filter能够实现更加强大的过滤功能,控制日志输出。自定义的过滤器中必须覆写filter方法,当filter的返回值判断为True则允许输出,反之不允许输出。例如过滤包含敏感信息的日志,过滤器定义如下:
import logging class CountryFilter(logging.Filter): def filter(self,record): return "America" not in record.getMessage() logger = logging.getLogger() handler = logging.StreamHandler() logger.addHandler(handler) logger.setLevel(logging.DEBUG) logger.addFilter(CountryFilter()) logger.critical('I love America') logger.debug('I love China')输出结果: I love China 可以看到,虽然第一条日志记录的日志等级更高,但是因为包含了过滤器中包含的敏感信息,所以不被允许输出。
4 logging奇淫巧技
4.1 记录异常信息:捕获traceback
如果在日志中,只是记录发生了异常,那其实作用不大,如果traceback也记录到日志中,那就完美了。强大的logging确实也提供了这一功能,而且使用也很简单:import logging logger = logging.getLogger(__name__) handler = logging.FileHandler('./.log',encoding='utf-8') logger.setLevel(logging.DEBUG) # 定义格式器,添加到处理器中 fmt = '%(asctime)s , %(levelname)s , %(filename)s %(funcName)s line %(lineno)s , %(message)s' datefmt = '%Y-%m-%d %H:%M:%S %a' log_fmt = logging.Formatter(fmt=fmt, datefmt=datefmt) handler.setFormatter(log_fmt) logger.addHandler(handler) try: logger.info('Running …') 1/0 except Exception as e: logger.error('Exception occurs!',exc_info = True) # logger.exception(e) # 与上面这行效果一样运行后,文件.log会被写入以下内容: 2019-03-29 19:53:14 Fri , INFO , log_test2.py <module> line 15 , Running … 2019-03-29 19:53:14 Fri , ERROR , log_test2.py <module> line 18 , Exception occurs! Traceback (most recent call last): File "E:/myCode/test1/log_test2.py", line 16, in <module> 1/0 ZeroDivisionError: division by zero
4.2 多模块共享日志
在开发过程中,经常出现多个模块都需要记录日志的情况,也许你想到的做法是在一个模块中配置好一个logger并实例化,在需要用到的模块中进行导入,但如果不同模块的日志器配置有区别时,这种方法就不适用了,若是为每个模块都定义一个logger,所有配置都需要重新写入,有些繁琐。还记得上文中提到logging的日志器可以通过name属性进行分层吗?子日志器可以继承父日志器的配置,也可以重新配置,这就是logging给我们提供的多模块共享日志的解决方案。看代码: 模块main.py中的代码:import logging import log_child logger = logging.getLogger('main') logger.setLevel(logging.DEBUG) fmt = '%(name)s , %(asctime)s , %(levelname)s , %(filename)s %(funcName)s line %(lineno)s , %(message)s' datefmt = '%Y-%m-%d %H:%M:%S %a' log_fmt = logging.Formatter(fmt=fmt, datefmt=datefmt) handler = logging.FileHandler('./.log',encoding='utf-8') handler.setFormatter(log_fmt) logger.addHandler(handler) if __name__=='__main__': logger.debug('Running …') log_child.fun_child()模块child_log.py中的代码:
import logging logger = logging.getLogger('main.child') logger.setLevel(logging.DEBUG) def fun_child(): try: logger.info('Running …') 1 / 0 except Exception as e: logger.exception(e)运行main.py后,.log文件会被写入���下内容: main , 2019-03-29 20:23:32 Fri , DEBUG , main.py <module> line 16 , Running … main.child , 2019-03-29 20:23:32 Fri , INFO , log_child.py fun_child line 7 , Running … main.child , 2019-03-29 20:23:32 Fri , ERROR , log_child.py fun_child line 10 , division by zero Traceback (most recent call last): File "E:\myCode\test1\log_child.py", line 8, in fun_child 1 / 0 ZeroDivisionError: division by zero
4.3 使用配置文件配置logger
我们之前的程序中都是将对logger的配置一并写在程序中,但事实上,采用配置化编程的方式,将对logger的配置写在专门的配置文件中,例如写入json文件、conf文件、yaml文件等文件中,当需要实例化logger时,读取即可。下面以conf文件为例,通过代码注释的方式,介绍logging配置文件的书写方式。配置文件log.conf如下:[loggers] #固定写法,定义logger的模块 keys=root,log_1,log_2 #创建三个logger,root是父类,必需存在的,其他两个logger的name分别为 [logger_root] # 定制上面的logger,严格要求格式为"logger_loggername",必须通过loggername与上面的logger一一对应 level=DEBUG # 设置日志级别 qualname=root # 对于root,其实这里可以不填,默认就是root handlers=debugs #设置指定处理器,如果有多个处理器,中间以逗号分隔,这个名字待会儿 我们会以固定格式"handler_(value)"创建 [logger_log_1] level=INFO qualname=log_1 #除了root以外,必须要设置这个属性,用于定义打印输出时候的logger名 handlers=infos propagate=0 # 是否将消息想父日志传递,0表示不传递,1表示传递。如果向上传递,父日志器接收到消息后会以父日志器的配置再次处理该消息,所以可能所有多次输出 [logger_log_2] level=WARNING qualname=log_2 handlers=warns [handlers] #固定格式, 开始定义处理器 keys=debugs,infos,warns#定义过滤器名称,与上面出现的handlers的值一一对应,下面定义以handler_handlername格式定义 [handler_debugs] class=StreamHandler # 指定处理器的类名 level=DEBUG # 设置级别 formatter=form01 #定义格式器,名称为form01,下面会创建formatters,格式也是严格要求为formatter_formattername args=(sys.stdout,) # 控制台输出 [handler_infos] class=FileHandler level=INFO formatter=form02 args=('b.log','a') [handler_warns] class=FileHandler level=WARNING formatter=form02 args=('a.log','a')# 写入到文件,写入方式 [formatters] #固定格式 keys=form01,form02 #定义名称,下面会引用格式,与上面出现的formatter的值对应 [formatter_form01] format=%(asctime)s %(message)s # 定义消息输出格式,内容 datefmt=%Y-%m-%d %H:%M:%S #日期输出格式 [formatter_form02] format=%(asctime)s %(filename)s %(levelname)s %(message)s datefmt=%Y-%m-%d %H:%M:%S实例化logger:
# _*_coding:utf-8_*_ import logging from logging.config import fileConfig fileConfig('log.conf') root= logging.getLogger(name="root") log_1= logging.getLogger(name="log_1") log_2= logging.getLogger(name="log_2") root.debug('root_debug') root.info('root_info') root.warning('root_warning') log_1.debug('log_1_debug') log_1.info('log_1_info') log_1.warning('log_1_warning') log_2.debug('log_2_debug') log_2.info('log_2_info') log_2.warning('log_2_warning')程序运行后,控制台输出如下: 2019-03-29 21:43:24 root_debug 2019-03-29 21:43:24 root_info 2019-03-29 21:43:24 root_warning a.log文件将被写入以下内容: 2019-03-29 21:43:24 main.py INFO log_1_info 2019-03-29 21:43:24 main.py WARNING log_1_warning b.log文件将被写入以下内容: 2019-03-29 21:43:24 main.py WARNING log_2_warning
4.3 日志回滚
什么是日志回滚呢?咋一听,好像不知道是什么东西。日志回滚就是按照日期或者时间(有时候甚至是日志和时间综合作用),对日志进行分割或者删除。实际开发中经常需要用到,因为随着应用的持续运行,日志文件会越来越庞大,对系统的性能产生影响,所以有必要删除早起的日志。 logging中提供了两个处理器用于日志回滚,一个是RotatingFileHandler,它主要是根据日志文件的大小进行滚动,另一个是TimeRotatingFileHandler,它主要是根据时间进行滚动。 (1)根据文件大小进行回滚 按文件大小回滚的类是RotatingFileHandler:# -*- coding:utf-8 -*- import logging from logging.handlers import RotatingFileHandler logger = logging.getLogger('main') logger.setLevel(level = logging.INFO) # 定义一个RotatingFileHandler,最多备份三个日志文件, 每个日志文件最大1k file_handler = RotatingFileHandler(".log",maxBytes = 1*1024,backupCount = 3) file_handler.setLevel(logging.INFO) formatter = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s') file_handler.setFormatter(formatter) cons_handler = logging.StreamHandler() cons_handler.setLevel(logging.DEBUG) cons_handler.setFormatter(formatter) logger.addHandler(file_handler) logger.addHandler(cons_handler) if __name__=='__main__': while True: logger.debug("debug") logger.info("info") logger.warning("warning") logger.critical("critical")上述程序执行后,将持续在控制台输出所有的日志记录,日志记录文件有三个,循环向日志文件中写入日志,当文件大小达到1kb时,开始在另一个文件删除日志记录,并写入新的日志记录。 (2)根据时间进行回滚。 按文件时间回滚的类时TimeRotatingFileHandler,这一个类包含以下参数: filename :输出日志文件名的前缀,比如main.log when 是一个字符串的定义如下: “S”: Seconds “M”: Minutes “H”: Hours “D”: Days “W”: Week day (0=Monday) “midnight”: Roll over at midnight interval 是指等待多少个单位when的时间后
import time import logging import logging.handlers # logging初始化工作 logging.basicConfig() # logger的初始化工作 logger = logging.getLogger('main') logger.setLevel(logging.INFO) # 添加TimedRotatingFileHandler # 定义一个1秒换一次log文件的handler # 保留3个旧log文件 timefilehandler = logging.handlers.TimedRotatingFileHandler(".log", when='S', interval=1, backupCount=3) # 设置后缀名称,跟strftime的格式一样 timefilehandler.suffix = "%Y-%m-%d_%H-%M-%S.log" formatter = logging.Formatter('%(asctime)s|%(name)-12s: %(levelname)-8s %(message)s') timefilehandler.setFormatter(formatter) logger.addHandler(timefilehandler) while True: time.sleep(0.1) logger.debug("debug") logger.info("info") logger.warning("warning") logger.critical("critical")
5 总结
本篇系统得总结了Python内容的日志记录模块logging的用法,囊括了logging的大部分内容。掌握本篇内容,感觉在开发中基本没有问题。linuxboy的RSS地址:https://www.linuxboy.net/rssFeed.aspx
本文永久更新链接地址:https://www.linuxboy.net/Linux/2019-08/160159.htm
评论暂时关闭