啄木鸟社区里的Pythonic八荣八耻有一条:

以打印日志为荣 , 以单步跟踪为耻;

很多程序都有记录日志的需求,并且日志中包含的信息既有正常的程序访问日志,还可能有错误、警告等信息输出,python的logging模块提供了标准的日志接口,你可以通过它存储各种格式的日志,主要用于输出运行日志,可以设置输出日志的等级、日志保存路径、日志文件回滚等;

为什么不用print打印输出?

这种方式对于简单脚本型程序有用,但是如果是复杂的系统,最好不要用。首先,这些print是没用的输出,大量使用很有可能会被遗忘在代码里。再者,print 输出的所有信息都到了标准输出中,这将严重影响到你从标准输出中查看其它输出数据。

使用logging的优势:

a)你可以控制消息的级别,过滤掉那些并不重要的消息。

b)你可决定输出到什么地方,以及怎么输出。有许多的重要性别级可供选择,debug、info、warning、error 以及 critical。通过赋予 logger 或者 handler 不同的级别,你就可以只输出错误消息到特定的记录文件中,或者在调试时只记录调试信息。

下面让我们正式进入logging的世界:

1. logging日志框架

主要包括四部分:

  • Loggers: 可供程序直接调用的接口,app通过调用提供的api来记录日志
  • Handlers: 决定将日志记录分配至正确的目的地
  • Filters:对日志信息进行过滤, 提供更细粒度的日志是否输出的判断
  • Formatters: 制定最终记录打印的格式布局

1)loggers

loggers 就是程序可以直接调用的一个日志接口,可以直接向logger写入日志信息。logger并不是直接实例化使用的,而是通过logging.getLogger(name)来获取对象,事实上logger对象是单例模式,logging是多线程安全的,也就是无论程序中哪里需要打日志获取到的logger对象都是同一个。但是不幸的是logger并不支持多进程,这个在后面的章节再解释,并给出一些解决方案。

【注意】loggers对象是有父子关系的,当没有父logger对象时它的父对象是root,当拥有父对象时父子关系会被修正。举个例子,logging.getLogger("abc.xyz") 会创建两个logger对象,一个是abc父对象,一个是xyz子对象,同时abc没有父对象,所以它的父对象是root。但是实际上abc是一个占位对象(虚的日志对象),可以没有handler来处理日志。但是root不是占位对象,如果某一个日志对象打日志时,它的父对象会同时收到日志,所以有些使用者发现创建了一个logger对象时会打两遍日志,就是因为他创建的logger打了一遍日志,同时root对象也打了一遍日志。

2)Handlers

Handlers 将logger发过来的信息进行准确地分配,送往正确的地方。举个栗子,送往控制台或者文件或者both或者其他地方(进程管道之类的)。它决定了每个日志的行为,是之后需要配置的重点区域。

每个Handler同样有一个日志级别,一个logger可以拥有多个handler也就是说logger可以根据不同的日志级别将日志传递给不同的handler。当然也可以相同的级别传递给多个handlers这就根据需求来灵活的设置了。

3)Filters

Filters 提供了更细粒度的判断,来决定日志是否需要打印。原则上handler获得一个日志就必定会根据级别被统一处理,但是如果handler拥有一个Filter可以对日志进行额外的处理和判断。例如Filter能够对来自特定源的日志进行拦截or修改甚至修改其日志级别(修改后再进行级别判断)。

logger和handler都可以安装filter甚至可以安装多个filter串联起来。

4) Formatters

Formatters 指定了最终某条记录打印的格式布局。Formatter会将传递来的信息拼接成一条具体的字符串,默认情况下Format只会将信息%(message)s直接打印出来。Format中有一些自带的LogRecord属性可以使用,如下表格:

一个Handler只能拥有一个Formatter 因此如果要实现多种格式的输出只能用多个Handler来实现。

上图只是一部分,更详细的在docs.python.org里找logging模块:

2. 日志级别

在记录日志时, 日志消息都会关联一个级别(“级别”本质上是一个非负整数)。系统默认提供了6个级别,它们分别是:

可以给日志对象(Logger Instance)设置日志级别,低于该级别的日志消息将会被忽略,也可以给Hanlder设置日志级别,对于低于该级别的日志消息, Handler也会忽略。

3. 常用函数

如果想要快速码代码,可以直接看第4节,基本使用

1)logging.basicConfig([**kwargs]):

为日志模块配置基本信息。设置后可以直接使用logging来打印日志

kwargs 支持如下几个关键字参数:
filename :日志文件的保存路径。如果配置了些参数,将自动创建一个FileHandler作为Handler;
filemode :日志文件的打开模式。 默认值为’a’,表示日志消息以追加的形式添加到日志文件中。如果设为’w’, 那么每次程序启动的时候都会创建一个新的日志文件;
format :设置日志输出格式;
datefmt :定义日期格式;
level :设置日志的级别.对低于该级别的日志消息将被忽略;
stream :设置特定的流用于初始化StreamHandler;

logging.basicConfig(level=log_level, format='%(asctime)s %(filename)s[line:%(lineno)d] %(levelname)s %(message)s', datefmt='%a, %d %b %Y %H:%M:%S', filename='parser_result.log', filemode='w')logging.debug('This is debug message')
logging.info('This is info message')
logging.warning('This is warning message')

注意打印日志时logging后跟的是小写的等级,设置等级时跟的时大写的等级

2)logging.getLogger([name])

创建Logger对象。日志记录的工作主要由Logger对象来完成。在调用getLogger时要提供Logger的名称(注:多次使用相同名称来调用getLogger,返回的是同一个对象的引用。),Logger实例之间有层次关系,这些关系通过Logger名称来体现,如:

p = logging.getLogger(“root”)

c1 = logging.getLogger(“root.c1”)

c2 = logging.getLogger(“root.c2”)

例子中,p是父logger, c1,c2分别是p的子logger。c1, c2将继承p的设置。如果省略了name参数, getLogger将返回日志对象层次关系中的根Logger。

3)logging.getLevelName(lvl)

获取日志级别对应的名称。例如:

 View Code

4)logging.shutdown()

当不再使用日志系统的时候,调用该方法,它会将日志flush到对应的目标域上。一般在系统退出的时候调用。

Logger对象通过调用logging.getLogger(name)来创建,它有如下常用的方法和属性:

2 - a)Logger.setLevel(lvl):

设置日志的级别。对于低于该级别的日志消息将被忽略。下面一个例子演示setLevel方法:

 View Code

2 - b)打印消息

Logger.debug(msg [ ,*args [, **kwargs]])

记录DEBUG级别的日志信息。参数msg是信息的格式,args与kwargs分别是格式参数。

Logger.info(msg[ , *args[ , **kwargs] ] )

Logger.warnning(msg[ , *args[ , **kwargs] ] )

Logger.error(msg[ , *args[ , **kwargs] ] )

Logger.critical(msg[ , *args[ , **kwargs] ] )

记录相应级别的日志信息。参数的含义与Logger.debug一样。

2 - c)增加移除处理器

Logger.addHandler(hdlr)

Logger.removeHandler(hdlr)

添加/移除日志消息处理器。在讲述Handler时具体介绍。

2 - d)Logger.log(lvl, msg[ , *args[ , **kwargs] ] )

记录日志,参数lvl用户设置日志信息的级别。参数msg, *args, **kwargs的含义与Logger.debug一样。

2 - e)Logger.exception(msg[, *args])

以ERROR级别记录日志消息,异常跟踪信息将被自动添加到日志消息里。Logger.exception通过用在异常处理块中,如:

 View Code

2 - f)

Logger.addFilter(filt)

Logger.removeFilter(filt)

添加/移除日志消息过滤器。在讲述Filter时具体介绍。

2 - g)Logger.makeRecord(name, lvl, fn, lno, msg, args, exc_info[, func, extra])

创建LogRecord对象。日志消息被实例为一个LogRecord对象,并在日志类内处理。

4.基本使用

1) 简单的将日志打印到屏幕

1 import logging
2
3 logging.debug('this is debug message')
4 logging.info('this is info message')
5 logging.warning('this is warning message')
6
7 #打印结果:WARNING:root:this is warning message  

默认情况下,logging将日志打印到屏幕,日志级别为WARNING;
日志级别大小关系为:CRITICAL > ERROR > WARNING > INFO > DEBUG > NOTSET,当然也可以自己定义日志级别。

2)通过logging.basicConfig函数对日志的输出格式及方式做相关配置

 1 import logging  2   3 logging.basicConfig(level=logging.DEBUG, format='%(asctime)s - %(name)s - %(message)s')  4   5 logging.debug('this is debug message')  6 logging.info('this is info message')  7 logging.warning('this is warning message')  8   9 '''''
10 结果:
11 2017-08-23 14:22:25,713 - root - this is debug message
12 2017-08-23 14:22:25,713 - root - this is info message
13 2017-08-23 14:22:25,714 - root - this is warning message
14 '''  

logging.basicConfig函数各参数:
filename: 指定日志文件名
filemode: 和file函数意义相同,指定日志文件的打开模式,'w'或'a'
format: 指定输出的格式和内容,format可以输出很多有用信息,如上例所示:
 %(levelno)s: 打印日志级别的数值
 %(levelname)s: 打印日志级别名称
 %(pathname)s: 打印当前执行程序的路径,其实就是sys.argv[0]
 %(filename)s: 打印当前执行程序名
 %(funcName)s: 打印日志的当前函数
 %(lineno)d: 打印日志的当前行号
 %(asctime)s: 打印日志的时间
 %(thread)d: 打印线程ID
 %(threadName)s: 打印线程名称
 %(process)d: 打印进程ID
 %(message)s: 打印日志信息
datefmt: 指定时间格式,同time.strftime()
level: 设置日志级别,默认为logging.WARNING
stream: 指定将日志的输出流,可以指定输出到sys.stderr,sys.stdout或者文件,默认输出到sys.stderr,当stream和filename同时指定时,stream被忽略

3)将日志同时输出到文件和屏幕

 1 import logging2 logger = logging.getLogger(__name__)3 logger.setLevel(level = logging.INFO)4 handler = logging.FileHandler("log.txt")5 handler.setLevel(logging.INFO)6 formatter = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s')7 handler.setFormatter(formatter)8  9 console = logging.StreamHandler()
10 console.setLevel(logging.INFO)
11
12 logger.addHandler(handler)
13 logger.addHandler(console)
14
15 logger.info("Start print log")
16 logger.debug("Do something")
17 logger.warning("Something maybe fail.")
18 logger.info("Finish")

可以在log.txt文件和控制台中看到:

可以发现,logging有一个日志处理的主对象,其他处理方式都是通过addHandler添加进去,logging中包含的handler主要有如下几种:

4)传给syslogserver,邮箱

1 from logging import handlers
2
3 #日志传送到syslog server
4 syslog_handler = handlers.SysLogHandler(address=('192.168.168.1', 514))
5
6 #日志传送给邮箱
7 mail_handler = handlers.SMTPHandler('192.168.168.1', 'winter@126.com', 'elly@163.com', 'subject')
8 #邮件给多人
9 mail_handler = handlers.SMTPHandler('192.168.168.1', 'winter@126.com', ('elly@163.com', 'dxd@126.com'), 'subject')

5)日志回滚

如果你用 FileHandler 写日志,文件的大小会随着时间推移而不断增大。最终有一天它会占满你所有的磁盘空间。为了避免这种情况出现,你可以在你的生成环境中使用 RotatingFileHandler 替代 FileHandler。

import logging
from logging.handlers import RotatingFileHandler
logger = logging.getLogger(__name__)
logger.setLevel(level = logging.INFO)
#定义一个RotatingFileHandler,最多备份3个日志文件,每个日志文件最大1K
rHandler = RotatingFileHandler("log.txt",maxBytes = 1*1024,backupCount = 3)
rHandler.setLevel(logging.INFO)
formatter = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s')
rHandler.setFormatter(formatter)

console = logging.StreamHandler()
console.setLevel(logging.INFO)
console.setFormatter(formatter)

logger.addHandler(rHandler)
logger.addHandler(console)

logger.info("Start print log")
logger.debug("Do something")
logger.warning("Something maybe fail.")
logger.info("Finish")

5. 多模块使用logging配置

1)通过继承关系实现

 1 import logging2 3 logger = logging.getLogger('mainModule')4 logger.setLevel(level=logging.INFO)5 6 formatter = logging.Formatter(7     '%(asctime)s - %(name)s - %(levelname)s - %(message)s')8 9 handler = logging.FileHandler('log.txt')
10 handler.setLevel(logging.INFO)
11 handler.setFormatter(formatter)
12
13 console = logging.StreamHandler()
14 console.setLevel(logging.INFO)
15 console.setFormatter(formatter)
16
17 logger.addHandler(handler)
18 logger.addHandler(console)
19
20 # 在其他模块导入该日志接口module_logger即可
21 module_logger = logging.getLogger('mainModule.sub')
22 module_logger.info('this is another module using logging')

说明:

首先定义了logger'mainModule',并对它进行了配置,就可以在解释器进程里面的其他地方通过getLogger('mainModule')得到的对象都是一样的,不需要重新配置,可以直接使用。定义的该logger的子logger,都可以共享父logger的定义和配置,所谓的父子logger是通过命名来识别,任意以'mainModule'开头的logger都是它的子logger,例如'mainModule.sub'。

实际开发一个application,首先可以通过logging配置文件编写好这个application所对应的配置,可以生成一个根logger,如'PythonAPP',然后在主函数中通过fileConfig加载logging配置,接着在application的其他地方、不同的模块中,可以使用根logger的子logger,如'PythonAPP.Core','PythonAPP.Web'来进行log,而不需要反复的定义和配置各个模块的logger。

2)通过logging.config模块配置日志

 1 #logger.conf  2 ###############################################  3 [loggers]  4 keys=root,example01,example02  5 [logger_root]  6 level=DEBUG  7 handlers=hand01,hand02  8 [logger_example01]  9 handlers=hand01,hand02
10 qualname=example01
11 propagate=0
12 [logger_example02]
13 handlers=hand01,hand03
14 qualname=example02
15 propagate=0
16 ###############################################
17 [handlers]
18 keys=hand01,hand02,hand03
19 [handler_hand01]
20 class=StreamHandler
21 level=INFO
22 formatter=form02
23 args=(sys.stderr,)
24 [handler_hand02]
25 class=FileHandler
26 level=DEBUG
27 formatter=form01
28 args=('myapp.log', 'a')
29 [handler_hand03]
30 class=handlers.RotatingFileHandler
31 level=INFO
32 formatter=form02
33 args=('myapp.log', 'a', 10*1024*1024, 5)
34 ###############################################
35 [formatters]
36 keys=form01,form02
37 [formatter_form01]
38 format=%(asctime)s %(filename)s[line:%(lineno)d] %(levelname)s %(message)s
39 datefmt=%a, %d %b %Y %H:%M:%S
40 [formatter_form02]
41 format=%(name)-12s: %(levelname)-8s %(message)s
42 datefmt=%a, %d %b %Y %H:%M:%S  

example01

1 import logging
2 import logging.config
3
4 logging.config.fileConfig("logger.conf")
5 logger = logging.getLogger("example01")
6
7 logger.debug('This is debug message')
8 logger.info('This is info message')
9 logger.warning('This is warning message')  

example02

1 import logging
2 import logging.config
3
4 logging.config.fileConfig("logger.conf")
5 logger = logging.getLogger("example02")
6
7 logger.debug('This is debug message')
8 logger.info('This is info message')
9 logger.warning('This is warning message')  

python2.7以后,可以从字典中加载logging配置,也就意味着可以通过JSON或者YAML文件加载日志的配置

3)通过JSON加载日志配置

 1 {  2     "version":1,  3     "disable_existing_loggers":false,  4     "formatters":{  5         "simple":{  6             "format":"%(asctime)s - %(name)s - %(levelname)s - %(message)s"  7         }  8     },  9     "handlers":{
10         "console":{
11             "class":"logging.StreamHandler",
12             "level":"DEBUG",
13             "formatter":"simple",
14             "stream":"ext://sys.stdout"
15         },
16         "info_file_handler":{
17             "class":"logging.handlers.RotatingFileHandler",
18             "level":"INFO",
19             "formatter":"simple",
20             "filename":"info.log",
21             "maxBytes":"10485760",
22             "backupCount":20,
23             "encoding":"utf8"
24         },
25         "error_file_handler":{
26             "class":"logging.handlers.RotatingFileHandler",
27             "level":"ERROR",
28             "formatter":"simple",
29             "filename":"errors.log",
30             "maxBytes":10485760,
31             "backupCount":20,
32             "encoding":"utf8"
33         }
34     },
35     "loggers":{
36         "my_module":{
37             "level":"ERROR",
38             "handlers":["info_file_handler"],
39             "propagate":"no"
40         }
41     },
42     "root":{
43         "level":"INFO",
44         "handlers":["console","info_file_handler","error_file_handler"]
45     }
46 }  

通过JSON加载配置文件,然后通过logging.dictConfig配置logging,

 1 import json  2 import logging.config  3 import os  4    5 def setup_logging(default_path = "logging.json",default_level = logging.INFO,env_key = "LOG_CFG"):  6     path = default_path  7     value = os.getenv(env_key,None)  8     if value:  9         path = value
10     if os.path.exists(path):
11         with open(path,"r") as f:
12             config = json.load(f)
13             logging.config.dictConfig(config)
14     else:
15         logging.basicConfig(level = default_level)
16
17 def func():
18     logging.info("start func")
19
20     logging.info("exec func")
21
22     logging.info("end func")
23
24 if __name__ == "__main__":
25     setup_logging(default_path = "logging.json")
26     func()  

使用JSON的一个优点就是json是一个标准库,不需要额外安装。但是,有人更喜欢YAML。无论读起来还是写起来都比较容易

4)通过YAML文件配置

通过YAML文件进行配置,比JSON看起来更加简介明了,

 1 version: 1  2 disable_existing_loggers: False  3 formatters:  4         simple:  5             format: "%(asctime)s - %(name)s - %(levelname)s - %(message)s"  6 handlers:  7     console:  8             class: logging.StreamHandler  9             level: DEBUG
10             formatter: simple
11             stream: ext://sys.stdout
12     info_file_handler:
13             class: logging.handlers.RotatingFileHandler
14             level: INFO
15             formatter: simple
16             filename: info.log
17             maxBytes: 10485760
18             backupCount: 20
19             encoding: utf8
20     error_file_handler:
21             class: logging.handlers.RotatingFileHandler
22             level: ERROR
23             formatter: simple
24             filename: errors.log
25             maxBytes: 10485760
26             backupCount: 20
27             encoding: utf8
28 loggers:
29     my_module:
30             level: ERROR
31             handlers: [info_file_handler]
32             propagate: no
33 root:
34     level: INFO
35     handlers: [console,info_file_handler,error_file_handler]  

通过YAML加载配置文件,然后通过logging.dictConfig配置logging

 1 import yaml  2 import logging.config  3 import os  4    5 def setup_logging(default_path = "logging.yaml",default_level = logging.INFO,env_key = "LOG_CFG"):  6     path = default_path  7     value = os.getenv(env_key,None)  8     if value:  9         path = value
10     if os.path.exists(path):
11         with open(path,"r") as f:
12             config = yaml.load(f)
13             logging.config.dictConfig(config)
14     else:
15         logging.basicConfig(level = default_level)
16
17 def func():
18     logging.info("start func")
19
20     logging.info("exec func")
21
22     logging.info("end func")
23
24 if __name__ == "__main__":
25     setup_logging(default_path = "logging.yaml")
26     func()  

接下来,你就可以在运行程序的时候调用setup_logging来启动日志记录了。它默认会读取logging.json或logging.yaml文件。你也可以设置环境变量LOG_CFG从指定的路径加载日志配置,例如:

LOG_CFG = my_logging.json python my_server.py

如果你喜欢YAML:

LOG_CFG = my_logging.yaml python my_server.py

注意:配置文件中“disable_existing_loggers” 参数设置为 False;如果不设置为False,创建了 logger,然后你又在加载日志配置文件之前就导入了模块。logging.fileConfig 与 logging.dictConfig 默认情况下会使得已经存在的 logger 失效。那么,这些配置信息就不会应用到你的 Logger 上。“disable_existing_loggers” = False解决了这个问题

6. 捕捉异常并使用traceback记录它

出问题时记录下来是个好习惯,python中的traceback模块用于记录异常信息,我们可以在logger中记录下traceback

比如下面的例子:

1 try:
2     open('/path/to/does/not/exist', 'rb')
3 except (SystemExit, KeyboardInterrupt):
4     raise
5 except Exception, e:
6     logger.error('Failed to open file', exc_info=True)  

结果为:

ERROR:__main__:Failed to open file
Traceback (most recent call last):  File "example.py", line 6, in <module>  open('/path/to/does/not/exist', 'rb')
IOError: [Errno 2] No such file or directory: '/path/to/does/not/exist'  

你也可以调用 logger.exception(msg, _args),它等价于 logger.error(msg, exc_info=True, _args)。

 logger.error('Failed to open file', exc_info=True)  

替换为:

logger.exception('Failed to open file')  

7. logger间的继承关系

1) logger间存在继承关系

logger 通过名字来决定继承关系,如果一个logger的名字是"mydest",另一个logger的名字是"mydest.dest1" (getLogger("mydest.dest1")),那么就称后者是前者的子logger,会继承前者的配置。上面的代码没有指定logger,直接调用logging.debug等方法时,会使用所有logger的祖先类RootLogger

从上面的代码运行结果可以猜测出,该RootLogger设置的日志级别是logging.WARN,输出目的地是标准流。从源码可以更清楚的看出来:

root = RootLogger(WARNING)  #设置root用户的日志级别为WARNING  

至于rootLogger的输出目的地的配置,我们跟踪logging.debug的源代码来看一下:

1 def debug(msg, *args, **kwargs):
2     """
3     Log a message with severity 'DEBUG' on the root logger.
4     """
5 if len(root.handlers) == 0:
6     basicConfig()
7 root.debug(msg, *args, **kwargs) 

大约可以看到,如果rootLogger没有配置handler,就会不带参数运行basicConfig函数,我们看一下basicConfig的源代码:

 1 def basicConfig(**kwargs):2     #有帮助文档,这里不列出3     _acquireLock()4     try:5         if len(root.handlers) == 0:6             filename = kwargs.get("filename")7             if filename:8                 mode = kwargs.get("filemode", 'a')9                 hdlr = FileHandler(filename, mode)
10             else:
11                 stream = kwargs.get("stream")
12                 hdlr = StreamHandler(stream)
13             fs = kwargs.get("format", BASIC_FORMAT)
14             dfs = kwargs.get("datefmt", None)
15             fmt = Formatter(fs, dfs)
16             hdlr.setFormatter(fmt)
17             root.addHandler(hdlr)
18             level = kwargs.get("level")
19             if level is not None:
20                 root.setLevel(level)
21     finally:
22         _releaseLock()

因为参数为空,所以我们就看出了,该rootLoger使用了不带参数的StreamHandler,也可以看到诸如format之类的默认配置。之后我们 跟踪StreamHandler(因为我们想看到日志输出目的地的配置,而handler就是控制日志流向的,所以我们要跟踪它)的源代码:

 1 class StreamHandler(Handler):2     """3     A handler class which writes logging records, appropriately formatted,4     to a stream. Note that this class does not close the stream, as5     sys.stdout or sys.stderr may be used.6     """7 8     def __init__(self, stream=None):9         """
10         Initialize the handler.
11
12         If stream is not specified, sys.stderr is used.
13         """
14         Handler.__init__(self)
15         if stream is None:
16             stream = sys.stderr
17         self.stream = stream

不带参数的StreamHandler将会把日志流定位到sys.stderr流,标准错误流同样会输出到控制台。

2) basicConfig函数用来配置RootLogger

basicConfig函数仅用来配置RootLogger,rootLogger是所有Logger的祖先Logger,所以其他一切Logger会继承该Logger的配置。

3) 通过示例详细讨论Logger配置的继承关系

首先准备下继承条件:log2继承自log1,logger的名称可以随意,要注意‘.’表示的继承关系。

 1 # coding:utf-8   2 import logging  3   4 log1 = logging.getLogger("mydear")  5   6 log1.setLevel(logging.WARNING)  7   8 log1.addHandler(StreamHandler())  9
10 log2 = logging.getLogger("mydear.app")
11
12 log2.error("display")
13
14 log2.info("not display")   

a)level的继承

原则:子logger写日志时,优先使用本身设置了的level;如果没有设置,则逐层向上级父logger查询,直到查询到为止。最极端的情况是,使用rootLogger的默认日志级别logging.WARNING。

从源代码中看更为清晰, 感谢python的所见即所得:

 1 def getEffectiveLevel(self):2     """3     Get the effective level for this logger.4 5     Loop through this logger and its parents in the logger hierarchy,6     looking for a non-zero logging level. Return the first one found.7     """8     logger = self9     while logger:
10         if logger.level:
11             return logger.level
12         logger = logger.parent
13     return NOTSET

b)handler的继承

原则:先将日志对象传递给子logger的所有handler处理,处理完毕后,如果该子logger的propagate属性没有设置为0,则将日志对象向上传递给第一个父Logger,该父logger的所有handler处理完毕后,如果它的propagate也没有设置为0,则继续向上层传递,以此类推。最终的状态,要么遇到一个Logger,它的propagate属性设置为了0;要么一直传递直到rootLogger处理完毕。

在上面实例代码的基础上,我们再添加一句代码,即:

 1 import logging2 3 log1 = logging.getLogger("mydear")4 5 log1.setLevel(logging.WARNING)6 7 log1.addHandler(logging.StreamHandler())8 9 log2 = logging.getLogger("mydear.app")
10
11 log2.error("display")
12
13 log2.info("not display")
14
15 print log2.handlers  # 打印log2绑定的handler

输出结果为:

display
[]

说好的继承,但是子logger竟然没有绑定父类的handler,what's wrong?

看到下面调用handler的源代码,就真相大白了。可以理解成,这不是真正的(类)继承,只是"行为上的继承":

 1 def callHandlers(self, record):  2     """ 3     Pass a record to all relevant handlers. 4  5     Loop through all handlers for this logger and its parents in the 6     logger hierarchy. If no handler was found, output a one-off error 7     message to sys.stderr. Stop searching up the hierarchy whenever a 8     logger with the "propagate" attribute set to zero is found - that 9     will be the last logger whose handlers are called.
10     """
11     c = self
12     found = 0
13     while c:
14         for hdlr in c.handlers:
15             found = found + 1
16             if record.levelno >= hdlr.level:
17                 hdlr.handle(record)
18         if not c.propagate:
19             c = None  # break out
20         else:
21             c = c.parent
22     if (found == 0) and raiseExceptions and not self.manager.emittedNoHandlerWarning:
23         sys.stderr.write("No handlers could be found for logger"
24                          " \"%s\"\n" % self.name)
25         self.manager.emittedNoHandlerWarning = 1  

额,最简单的样例牵引出来这么多后台的逻辑,不过我们懂一下也是有好处的。

8. logging遇到多进程

在handler中有一个class配置,可能有些读者并不是很懂。其实这个是logging里面原先就写好的一些handler类,你可以在这里直接调用。class指向的类相当于具体处理的Handler的执行者。在logging的文档中可以知道这里所有的Handler类都是线程安全的(但是GIL的存在,多线程基本可以无视),大家可以放心使用。所以一般情况下python要实现并行操作或者并行计算的时候都是使用多进程。但是logging并不是进程安全的,如果是用多进程来输出日志,则只有一个进程会切换,其他进程会在原来的文件中继续打,还有可能某些进程切换的时候早就有别的进程在新的日志文件里打入东西了,那么他会无情删掉之,再建立新的日志文件。会很乱很乱,完全没法开心的玩耍。

现在我们就来解决这个问题,以日志回滚使用的TimedRotatingFileHandler 这个类为例:

1)线程不安全的原因

在解决之前,我们先看看为什么会导致这样的原因。
先将TimedRotatingFileHandler 的源代码贴上来,这部分是切换时所作的操作:

 1 def doRollover(self):2     """3     do a rollover; in this case, a date/time stamp is appended to the filename4     when the rollover happens.  However, you want the file to be named for the5     start of the interval, not the current time.  If there is a backup count,6     then we have to get a list of matching filenames, sort them and remove7     the one with the oldest suffix.8     """9     if self.stream:
10         self.stream.close()
11         self.stream = None
12     # get the time that this sequence started at and make it a TimeTuple
13     currentTime = int(time.time())
14     dstNow = time.localtime(currentTime)[-1]
15     t = self.rolloverAt - self.interval
16     if self.utc:
17         timeTuple = time.gmtime(t)
18     else:
19         timeTuple = time.localtime(t)
20         dstThen = timeTuple[-1]
21         if dstNow != dstThen:
22             if dstNow:
23                 addend = 3600
24             else:
25                 addend = -3600
26             timeTuple = time.localtime(t + addend)
27     dfn = self.baseFilename + "." + time.strftime(self.suffix, timeTuple)
28     if os.path.exists(dfn):
29         os.remove(dfn)
30     # Issue 18940: A file may not have been created if delay is True.
31     if os.path.exists(self.baseFilename):
32         os.rename(self.baseFilename, dfn)
33     if self.backupCount > 0:
34         for s in self.getFilesToDelete():
35             os.remove(s)
36     if not self.delay:
37         self.stream = self._open()
38     newRolloverAt = self.computeRollover(currentTime)
39     while newRolloverAt <= currentTime:
40         newRolloverAt = newRolloverAt + self.interval
41     # If DST changes and midnight or weekly rollover, adjust for this.
42     if (self.when == 'MIDNIGHT' or self.when.startswith('W')) and not self.utc:
43         dstAtRollover = time.localtime(newRolloverAt)[-1]
44         if dstNow != dstAtRollover:
45             if not dstNow:  # DST kicks in before next rollover, so we need to deduct an hour
46                 addend = -3600
47             else:  # DST bows out before next rollover, so we need to add an hour
48                 addend = 3600
49             newRolloverAt += addend
50     self.rolloverAt = newRolloverAt

我们观察 if os.path.exists(dfn) 这一行开始,这里的逻辑是如果 dfn 这个文件存在,则要先删除掉它,然后将 baseFilename 这个文件重命名为 dfn 文件。然后再重新打开 baseFilename这个文件开始写入东西。那么这里的逻辑就很清楚了

a)假设当前日志文件名为 current.log 切分后的文件名为 current.log.2016-06-01

b)判断 current.log.2016-06-01 是否存在,如果存在就删除

c)将当前的日志文件名 改名为current.log.2016-06-01

d)重新打开新文件(我观察到源代码中默认是”a” 模式打开,之前据说是”w”)

于是在多进程的情况下,一个进程切换了,其他进程的句柄还在 current.log.2016-06-01 还会继续往里面写东西。又或者一个进程执行切换了,会把之前别的进程重命名的 current.log.2016-06-01 文件直接删除。又或者还有一个情况,当一个进程在写东西,另一个进程已经在切换了,会造成不可预估的情况发生。还有一种情况两个进程同时在切文件,第一个进程正在执行第3步,第二进程刚执行完第2步,然后第一个进程 完成了重命名但还没有新建一个新的 current.log 第二个进程开始重命名,此时第二个进程将会因为找不到 current 发生错误。如果第一个进程已经成功创建了 current.log 第二个进程会将这个空文件另存为 current.log.2016-06-01。那么不仅删除了日志文件,而且,进程一认为已经完成过切分了不会再切,而事实上他的句柄指向的是current.log.2016-06-01。
好了这里看上去很复杂,实际上就是因为对于文件操作时,没有对多进程进行一些约束,而导致的问题。
那么如何优雅地解决这个问题呢。我提出了两种方案,当然我会在下面提出更多可行的方案供大家尝试。

2)解决方案1

先前我们发现 TimedRotatingFileHandler 中逻辑的缺陷。我们只需要稍微修改一下逻辑即可:

a)判断切分后的文件 current.log.2016-06-01 是否存在,如果不存在则进行重命名。(如果存在说明有其他进程切过了,我不用切了,换一下句柄即可)

b)以”a”模式 打开 current.log
发现修改后就这么简单~
talking is cheap show me the code:

 1 class SafeRotatingFileHandler(TimedRotatingFileHandler):  2   3 def __init__( self, filename, when='h', interval=1, backupCount=0, encoding=None, delay=False, utc=False):  4     TimedRotatingFileHandler.__init__( self, filename, when, interval, backupCount, encoding, delay, utc)  5   6 """ 7 Override doRollover 8 lines commanded by "##" is changed by cc 9 """
10
11 def doRollover(self):
12     """
13     do a rollover; in this case, a date/time stamp is appended to the filename
14     when the rollover happens.  However, you want the file to be named for the
15     start of the interval, not the current time.  If there is a backup count,
16     then we have to get a list of matching filenames, sort them and remove
17     the one with the oldest suffix.
18     Override,   1. if dfn not exist then do rename
19                 2. _open with "a" model
20     """
21
22     if self.stream:
23         self.stream.close()
24         self.stream = None
25     # get the time that this sequence started at and make it a TimeTuple
26     currentTime = int(time.time())
27     dstNow = time.localtime(currentTime)[-1]
28     t = self.rolloverAt - self.interval
29     if self.utc:
30         timeTuple = time.gmtime(t)
31     else:
32         timeTuple = time.localtime(t)
33         dstThen = timeTuple[-1]
34         if dstNow != dstThen:
35             if dstNow:
36                 addend = 3600
37             else:
38                 addend = -3600
39             timeTuple = time.localtime(t + addend)
40     dfn = self.baseFilename + "." + time.strftime(self.suffix, timeTuple)
41     # if os.path.exists(dfn):
42     # os.remove(dfn)
43     # Issue 18940: A file may not have been created if delay is True.
44     # if os.path.exists(self.baseFilename):
45     if not os.path.exists(dfn) and os.path.exists(self.baseFilename):
46         os.rename(self.baseFilename, dfn)
47     if self.backupCount > 0:
48         for s in self.getFilesToDelete():
49             os.remove(s)
50     if not self.delay:
51         self.mode = "a"
52         self.stream = self._open()
53     newRolloverAt = self.computeRollover(currentTime)
54     while newRolloverAt <= currentTime:
55         newRolloverAt = newRolloverAt + self.interval
56     # If DST changes and midnight or weekly rollover, adjust for this.
57     if (self.when == 'MIDNIGHT' or self.when.startswith('W')) and not self.utc:
58         dstAtRollover = time.localtime(newRolloverAt)[-1]
59         if dstNow != dstAtRollover:
60             if not dstNow:  # DST kicks in before next rollover, so we need to deduct an hour
61                 addend = -3600
62             else:  # DST bows out before next rollover, so we need to add an hour
63                 addend = 3600
64             newRolloverAt += addend
65     self.rolloverAt = newRolloverAt  

不要以为代码那么长,其实修改部分就是 “##” 注释的地方而已,其他都是照抄源代码。这个类继承了 TimedRotatingFileHandler 重写了这个切分的过程。这个解决方案十分优雅,改换的地方非常少,也十分有效。但有网友提出,这里有一处地方依然不完美,就是rename的那一步,如果就是这么巧,同时两个或者多个进程进入了 if 语句,先后开始 rename 那么依然会发生删除掉日志的情况。确实这种情况确实会发生,由于切分文件一天才一次,正好切分的时候同时有两个Handler在操作,又正好同时走到这里,也是蛮巧的,但是为了完美,可以加上一个文件锁,if 之后加锁,得到锁之后再判断一次,再进行rename这种方式就完美了。代码就不贴了,涉及到锁代码,影响美观。

3)解决方案2

我认为最简单有效的解决方案。重写FileHandler类(这个类是所有写入文件的Handler都需要继承的TimedRotatingFileHandler 就是继承的这个类;我们增加一些简单的判断和操作就可以。
我们的逻辑是这样的:

a)判断当前时间戳是否与指向的文件名是同一个时间

b)如果不是,则切换 指向的文件即可
结束,是不是很简单的逻辑。
talking is cheap show me the code:

 1 class SafeFileHandler(FileHandler):  2   3 def __init__(self, filename, mode, encoding=None, delay=0):  4     """  5     Use the specified filename for streamed logging  6     """  7     if codecs is None:  8         encoding = None  9     FileHandler.__init__(self, filename, mode, encoding, delay)
10     self.mode = mode
11     self.encoding = encoding
12     self.suffix = "%Y-%m-%d"
13     self.suffix_time = ""
14 def emit(self, record):
15     """
16     Emit a record.
17     Always check time
18     """
19     try:
20         if self.check_baseFilename(record):
21             self.build_baseFilename()
22         FileHandler.emit(self, record)
23     except (KeyboardInterrupt, SystemExit):
24         raise
25     except:
26         self.handleError(record)
27 def check_baseFilename(self, record):
28     """
29     Determine if builder should occur.
30     record is not used, as we are just comparing times,
31     but it is needed so the method signatures are the same
32     """
33     timeTuple = time.localtime()
34     if self.suffix_time != time.strftime(self.suffix, timeTuple) or not os.path.exists(
35                             self.baseFilename + '.' + self.suffix_time):
36         return 1
37     else:
38         return 0
39 def build_baseFilename(self):
40     """
41     do builder; in this case,
42     old time stamp is removed from filename and
43     a new time stamp is append to the filename
44     """
45     if self.stream:
46         self.stream.close()
47         self.stream = None
48     # remove old suffix
49     if self.suffix_time != "":
50         index = self.baseFilename.find("." + self.suffix_time)
51         if index == -1:
52             index = self.baseFilename.rfind(".")
53         self.baseFilename = self.baseFilename[:index]
54     # add new suffix
55     currentTimeTuple = time.localtime()
56     self.suffix_time = time.strftime(self.suffix, currentTimeTuple)
57     self.baseFilename = self.baseFilename + "." + self.suffix_time
58     self.mode = 'a'
59     if not self.delay:
60         self.stream = self._open()  

check_baseFilename 就是执行逻辑1判断;build_baseFilename 就是执行逻辑2换句柄。就这么简单完成了。
这种方案与之前不同的是,当前文件就是 current.log.2016-06-01 ,到了明天当前文件就是current.log.2016-06-02 没有重命名的情况,也没有删除的情况。十分简洁优雅。也能解决多进程的logging问题。

4)解决方案3---进程安全的ConcurrentLogHandler

如果多进程多线程使用,推荐 ConcurrentLogHandler,需要安装

安装:

pip install ConcurrentLogHandler

a)使用案例一

 1 def init_log():2     logfile = "/data1/restful_log/restful_api_thread.log"3     filesize = 800*1024*10244     log = getLogger()5     rotate_handler = ConcurrentRotatingFileHandler(logfile, "a", filesize, encoding="utf-8")6 7     datefmt_str = '%Y-%m-%d %H:%M:%S'8     format_str = '%(asctime)s\t%(levelname)s\t%(message)s '9     formatter = Formatter(format_str, datefmt_str)
10     rotate_handler.setFormatter(formatter)
11
12     log.addHandler(rotate_handler)
13     log.setLevel(WARN)
14
15     return log

ConcurrentRotatingFileHandler参数说明: 
filename: 日志文件地址,相对地址或绝对地址均可

mode: 默认为"a"

maxBytes:文件长度,超过最大长度自动分片,最初日志都会写入filename里面,到达设置的最大长度之后进行分片,分片后文件名为filename.1 filename.2,以此类推

backupCount:最大日志文件保留数量,默认为0即不会删除日志文件

encoding:日志文件编码格式,默认为gbk

b)使用案例二

建一个目录,下面的文件都放到这个目录中:

logging-config.yaml

 1 version: 1    2     3 formatters:    4     simple:    5         format: '%(asctime)s - %(name)s - %(levelname)s - %(message)s'    6     7 handlers:    8     console:    9         class: logging.StreamHandler
10         level: DEBUG
11         formatter: simple
12         stream: ext://sys.stdout
13
14 loggers:
15     simpleExample:
16         level: DEBUG
17         handlers: [console]
18         propagate: no
19
20 root:
21     level: DEBUG
22     handlers: [console]    

testlogging.py

  1 #!/usr/bin/python2.7    2 #-*- coding: UTF-8 -*-    3 #    4 # Using ConcurrentLogHandler:    5 #   wget https://pypi.python.org/packages/fd/e5/0dc4f256bcc6484d454006b02f33263b20f762a433741b29d53875e0d763/ConcurrentLogHandler-0.9.1.tar.gz#md5=9609ecc4c269ac43f0837d89f12554c3    6 #   cd ConcurrentLogHandler-0.9.1    7 #   python2.7 setup.py install    8 ###########################################################    9 import logging, logging.config    10 import cloghandler    11     12 import yaml    13     14 ###########################################################    15 # create logger    16 # 使用代码创建logger    17 logger = logging.getLogger('simple_example')    18 logger.setLevel(logging.DEBUG)    19     20 # create console handler and set level to debug    21 ch = logging.StreamHandler()    22 ch.setLevel(logging.DEBUG)    23     24 # create formatter    25 formatter = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s')    26     27 # add formatter to ch    28 ch.setFormatter(formatter)    29     30 # add ch to logger    31 logger.addHandler(ch)    32     33 # 'application' code    34 logger.debug('debug message')    35 logger.info('info message')    36 logger.warn('warn message')    37 logger.error('error message')    38 logger.critical('critical message')    39     40     41 ###########################################################    42 # basicConfig    43 logging.basicConfig(format='%(asctime)s %(message)s', datefmt='%m/%d/%Y %I:%M:%S %p')    44 logging.warning('is when this event was logged.')    45     46     47 ###########################################################    48 # using yaml config file    49 f = open("logging-config.yaml")    50 dictcfg = yaml.load(f)    51 f.close()    52     53 logging.config.dictConfig(dictcfg)    54     55 #logging.config.fileConfig("logging.config")    56 log = logging.getLogger("root")    57 log.info("==YAML== Here is a very exciting log message")    58     59 ###########################################################    60 # using ini config file    61 logging.config.fileConfig("logging-config.ini")    62 log = logging.getLogger("simpleExample")    63 log.info("==INI== Here is a very exciting log message")    64     65     66 ###########################################################    67 # using inline code config    68 logging.config.dictConfig({    69     'version': 1,    70     'disable_existing_loggers': True,    71     'formatters': {    72         'verbose': {    73             'format': "[%(asctime)s] %(levelname)s [%(name)s:%(lineno)s] %(message)s",    74             'datefmt': "%Y-%m-%d %H:%M:%S",    75         },    76         'simple': {    77             'format': '%(levelname)s %(message)s',    78         },    79     },    80     'handlers': {    81         'null': {    82             'level': 'DEBUG',    83             'class': 'logging.NullHandler',    84         },    85         'console': {    86             'level': 'DEBUG',    87             'class': 'logging.StreamHandler',    88             'formatter': 'verbose',    89         },    90         'file': {    91             'level': 'DEBUG',    92             'class': 'cloghandler.ConcurrentRotatingFileHandler',    93             'maxBytes': 1024 * 1024 * 10,   # 当达到10MB时分割日志    94             'backupCount': 10,              # 最多保留10份文件    95             'delay': True,                  # If delay is true, file opening is deferred until the first call to emit    96             'filename': 'sample-site.log',    97             'formatter': 'verbose',    98         },    99         'file2': {
100             'level': 'DEBUG',
101             'class': 'cloghandler.ConcurrentRotatingFileHandler',
102             'maxBytes': 1024 * 1024 * 10,   # 当达到10MB时分割日志
103             'backupCount': 10,              # 最多保留10份文件
104             'delay': True,                  # If delay is true, file opening is deferred until the first call to emit
105             'filename': 'sample-site2.log',
106             'formatter': 'verbose',
107         },
108     },
109     'loggers': {
110         '': {
111             'handlers': ['file'],
112             'level': 'INFO',
113         },
114         'root': {
115             'handlers': ['console'],
116             'level': 'INFO',
117             'propagate': 0,
118         },
119         'root2': {
120             'handlers': ['console'],
121             'level': 'INFO',
122             'propagate': 1,
123         },
124     },
125 })
126
127 logger = logging.getLogger("root")
128 logger.info("==== Here is a very exciting log message")
129
130 logger = logging.getLogger("root2")
131 logger.info("==== Here is a very exciting log message2")   

9. 小知识点

1)使用__name__作为logger的名称

虽然不是非得将 logger 的名称设置为 __name__ ,但是这样做会给我们带来诸多益处。在 python 中,变量 __name__ 的名称就是当前模块的名称。比如,在模块 “foo.bar.my_module” 中调用 logger.getLogger(__name__) 等价于调用logger.getLogger(“foo.bar.my_module”) 。当你需要配置 logger 时,你可以配置到 “foo” 中,这样包 foo 中的所有模块都会使用相同的配置。当你在读日志文件的时候,你就能够明白消息到底来自于哪一个模块。

2)全局共享logging配置

其实很简单,只需要执行:

logging.basicConfig(filename=‘', level=logging.DEBUG, filemode='w', format='%(asctime)s - %(name)s - %(levelname)s - %(message)s')

然后就可以在任何地方打印日志即可

logging.leve('')

暂时就到这里,以后继续扩展

logging模块详细使用相关推荐

  1. python之 logging模块详细使用【转载】

    很多程序都有记录日志的需求,并且日志中包含的信息既有正常的程序访问日志,还可能有错误.警告等信息输出,python的logging模块提供了标准的日志接口,你可以通过它存储各种格式的日志,主要用于输出 ...

  2. python 日志 logging模块(详细解析)

    1 基本使用 转自:https://www.cnblogs.com/wf-linux/archive/2018/08/01/9400354.html 配置logging基本的设置,然后在控制台输出日志 ...

  3. [zz]很详细,涵盖了多数场景!推荐 - python 的日志logging模块学习

    http://blog.csdn.net/yatere/article/details/6655445 1.简单的将日志打印到屏幕 import logging logging.debug('This ...

  4. Python实战之logging模块使用详解

    用Python写代码的时候,在想看的地方写个print xx 就能在控制台上显示打印信息,这样子就能知道它是什么了,但是当我需要看大量的地方或者在一个文件中查看的时候,这时候print就不大方便了,所 ...

  5. python处理日志_python日志处理(logging模块)

    文章非原创,搬运自@云游道士博客: 另外,这篇文章可以作为参考: 本节内容 日志相关概念 logging模块简介 使用logging提供的模块级别的函数记录日志 logging模块日志流处理流程 使用 ...

  6. python logging模块的作用_Python 日志模块logging分析及使用-2

    本文作为Python日志模块的补充,主要介绍日志回滚RotatingFileHandler和TimedRotatingFileHandler的使用,以及其所带来的问题.Logger对象的日志等级是如何 ...

  7. Python入门:常用模块—logging模块

    logging日志可以分为:debug(),info(),warning(),error(),critical() 5个级别 最简单用法 import logginglogging.warning(& ...

  8. Python之日志处理(logging模块)

    From: https://www.cnblogs.com/yyds/p/6901864.html 本节内容 日志相关概念 logging模块简介 使用logging提供的模块级别的函数记录日志 lo ...

  9. python日志模块_Python之日志处理(logging模块)

    转载自:https://www.cnblogs.com/yyds/p/6901864.html 本节内容 日志相关概念 logging模块简介 使用logging提供的模块级别的函数记录日志 logg ...

最新文章

  1. 【Javascript基础】
  2. 【深度学习】弱/半监督学习解决医学数据集规模小、数据标注难问题
  3. 洛谷 P3177 [HAOI2015]树上染色
  4. LeetCode Algorithm 242. 有效的字母异位词
  5. 简单常用滤波算法C语言实现
  6. 经典算法系列之(一) - BitMap [数据的压缩存储]
  7. Directory /opt/jfrog/artifactory/var has bad permissions for user id 1030
  8. spring事务管理器的作用_【面试必问】Spring中的事务管理详解
  9. 训练和测试自己的图像集
  10. java 获取field类型_获取Java类中所有Field
  11. 经济学基础(本)【1】
  12. 网络编程学习(11)/ FTP项目(5) ——文件上传和上传断点续存功能
  13. 【Ubuntu】安装企业微信(Wine)
  14. Linux ftrace 1.1、ring buffer
  15. JVM知识点整理2——(类加载)
  16. 23个部门联合发文:加快5G网络等信息基础设施建设和商用步伐,推动车联网部署应用...
  17. 百城价格房价周期和郑州、武汉房价比较分析
  18. 生成MySQL数据库表报错:Error Code: 1022. Can't write; duplicate key in table '#sql-e88_23'
  19. 微信小程序网络请求配置问题及本地网络请求测试解决方案
  20. 富甲一方的MetaRim震撼来袭,是一个结合元宇宙链游的NFT机甲

热门文章

  1. 2022年最新春招作战表…
  2. one 主格 复数 宾格_数字 主格宾格复数所有格
  3. B/S文件上传下载解决方案
  4. 记录用retinaNet执行DDSM代码中的问题(求精度的过程中出现的错误)
  5. python读书心得体会范文_读书心得体会范文10篇完美版
  6. 计算机毕业设计SSM电影院购票系统【附源码数据库】
  7. 音质好的蓝牙耳机有哪些?音质好的蓝牙耳机推荐
  8. Java虚拟机(一)结构原理与运行时数据区域
  9. FA(萤火虫算法)MATLAB源码详细中文注解
  10. 系统镜像ISO、GHO、WIM、ESD的区别