1. logging介绍

 

Python的logging模块提供了通用的日志系统,可以方便第三方模块或者是应用使用。这个模块提供不同的日志级别,并可以采用不同的方式记录日志,比如文件,HTTP GET/POST,SMTP,Socket等,甚至可以自己实现具体的日志记录方式。

logging模块与log4j的机制是一样的,只是具体的实现细节不同。

模块提供logger,handler,filter,formatter:

1)logger:提供日志接口,供应用代码使用。logger最长用的操作有两类:配置和发送日志消息。可以通过logging.getLogger(name)获取logger对象,如果不指定name则返回root对象,多次使用相同的name调用getLogger方法返回同一个logger对象。

2)handler:将日志记录(log record)发送到合适的目的地(destination),比如文件,socket等。一个logger对象可以通过addHandler方法添加0到多个handler,每个handler又可以定义不同日志级别,以实现日志分级过滤显示。

3)filter:提供一种优雅的方式决定一个日志记录是否发送到handler。

4)formatter:指定日志记录输出的具体格式。formatter的构造方法需要两个参数:消息的格式字符串和日期字符串,这两个参数都是可选的。

与log4j类似,logger,handler和日志消息的调用可以有具体的日志级别(Level),只有在日志消息的级别大于logger和handler的级别。

 

RotatingFileHandler:

 

  1. #!/usr/bin/python  
  2. # -*- coding:utf-8 -*-  
  3. #  
  4. # ithomer.net  
  5.   
  6. import logging  
  7. import logging.handlers  
  8.   
  9. LOG_FILE = 'tst.log'  
  10.   
  11. handler = logging.handlers.RotatingFileHandler(LOG_FILE, maxBytes = 1024*1024, backupCount=5)  
  12.   
  13. fmt = '%(asctime)s - %(filename)s:%(lineno)s - %(name)s - %(levelname)s - %(message)s'  
  14. formatter = logging.Formatter(fmt)  
  15. handler.setFormatter(formatter)  
  16.   
  17. logger = logging.getLogger('tst')  
  18. logger.addHandler(handler)  
  19. logger.setLevel(logging.DEBUG)  
  20.   
  21. logger.info('info msg')  
  22. logger.debug('debug msg')  

 

运行结果(tst.log日志文件内容):
2013-11-28 21:19:25,442 - logtest3.py:21 - tst - INFO - info msg
2013-11-28 21:19:25,442 - logtest3.py:22 - tst - DEBUG - debug msg

 

TimedRotatingFileHandler:

 

  1. #!/usr/bin/env python  
  2. # -*- coding: utf-8 -*-  
  3.   
  4. import logging  
  5. import logging.handlers  
  6.   
  7. def main():  
  8.     logger = logging.getLogger()  
  9.     logger.setLevel(logging.DEBUG)  
  10.       
  11.     handler = logging.handlers.TimedRotatingFileHandler("test.log"'D')  
  12.     # fmt = logging.Formatter("%(asctime)s - %(pathname)s - %(filename)s - %(funcName)s - %(lineno)s - %(levelname)s - %(message)s", "%Y-%m-%d %H:%M:%S")  
  13.     fmt = logging.Formatter("%(asctime)s - %(pathname)s - %(filename)s - %(funcName)s - %(lineno)s - %(levelname)s - %(message)s")  
  14.     handler.setFormatter(fmt)  
  15.     logger.addHandler(handler)  
  16.       
  17.     logger.debug("debug msg")  
  18.     logger.info("info msg")  
  19.     logger.warn("warn msg")  
  20.     logger.warning("warning msg")  
  21.     logger.error("error msg")  
  22.     logger.fatal("fatal msg")  
  23.     logger.critical("critical msg")  
  24.   
  25. if __name__ == "__main__":  
  26.     main()  

运行结果:

 

 

  1. 2013-12-31 17:39:07,093 - /home/homer/workspace/myPython/com/mylogging.py - mylogging.py - main - 17 - DEBUG - debug msg  
  2. 2013-12-31 17:39:07,093 - /home/homer/workspace/myPython/com/mylogging.py - mylogging.py - main - 18 - INFO - info msg  
  3. 2013-12-31 17:39:07,093 - /home/homer/workspace/myPython/com/mylogging.py - mylogging.py - main - 19 - WARNING - warn msg  
  4. 2013-12-31 17:39:07,093 - /home/homer/workspace/myPython/com/mylogging.py - mylogging.py - main - 20 - WARNING - warning msg  
  5. 2013-12-31 17:39:07,093 - /home/homer/workspace/myPython/com/mylogging.py - mylogging.py - main - 21 - ERROR - error msg  
  6. 2013-12-31 17:39:07,093 - /home/homer/workspace/myPython/com/mylogging.py - mylogging.py - main - 22 - CRITICAL - fatal msg  
  7. 2013-12-31 17:39:07,093 - /home/homer/workspace/myPython/com/mylogging.py - mylogging.py - main - 23 - CRITICAL - critical msg  

 

 

关于formatter的配置,采用的是%(<dict key>)s的形式,就是字典的关键字替换。提供的关键字包括:

 

 

Format Description
%(name)s Name of the logger (logging channel).
%(levelno)s Numeric logging level for the message (DEBUGINFOWARNINGERRORCRITICAL).
%(levelname)s Text logging level for the message ('DEBUG''INFO''WARNING''ERROR''CRITICAL').
%(pathname)s Full pathname of the source file where the logging call was issued (if available).
%(filename)s Filename portion of pathname.
%(module)s Module (name portion of filename).
%(funcName)s Name of function containing the logging call.
%(lineno)d Source line number where the logging call was issued (if available).
%(created)f Time when the LogRecord was created (as returned by time.time()).
%(relativeCreated)d Time in milliseconds when the LogRecord was created, relative to the time the logging module was loaded.
%(asctime)s Human-readable time when the LogRecord was created. By default this is of the form “2003-07-08 16:49:45,896” (the numbers after the comma are millisecond portion of the time).
%(msecs)d Millisecond portion of the time when the LogRecord was created.
%(thread)d Thread ID (if available).
%(threadName)s Thread name (if available).
%(process)d Process ID (if available).
%(message)s The logged message, computed as msg % args.

 

 

 

2. logging的配置

logging的配置可以采用python代码或是配置文件。python代码的方式就是在应用的主模块中,构建handler,handler,formatter等对象。而配置文件的方式是将这些对象的依赖关系分离出来放在文件中。比如前面的例子就类似于python代码的配置方式。这里看一下采用配置文件的方式。

 

  1. #!/usr/bin/python  
  2. # -*- coding:utf-8 -*-  
  3. #  
  4. # ithomer.net  
  5.   
  6. import logging  
  7. import logging.config  
  8.   
  9. LOG_FILE = 'tst.log'  
  10.   
  11. logging.config.fileConfig('logging.conf')  
  12.   
  13. # instance of logging  
  14. logger = logging.getLogger('tst')  
  15.   
  16. logger.debug('debug msg')  
  17. logger.info('info msg')  
  18. logger.warn('warn msg')  
  19. logger.error('error msg')  
  20. logger.critical('critical msg')  

 

loggin.conf采用了模式匹配的方式进行配置,正则表达式是r'^[(.*)]$',从而匹配出所有的组件。对于同一个组件具有多个实例的情况使用逗号‘,’进行分隔。对于一个实例的配置采用componentName_instanceName配置块。使用这种方式还是蛮简单的。

 

  1. [loggers]  
  2. keys=root,tst  
  3.   
  4. [handlers]  
  5. keys=consoleHandler  
  6.   
  7. [formatters]  
  8. keys=tstFormatter  
  9.   
  10. [logger_root]  
  11. level=DEBUG  
  12. handlers=consoleHandler  
  13.   
  14. [logger_tst]  
  15. level=DEBUG  
  16. handlers=consoleHandler  
  17. qualname=tst  
  18. propagate=0  
  19.   
  20. [handler_consoleHandler]  
  21. class=StreamHandler  
  22. level=DEBUG  
  23. formatter=tstFormatter  
  24. args=(sys.stdout,)  
  25.   
  26. [formatter_tstFormatter]  
  27. format=%(asctime)s - %(filename)s:%(lineno)s - %(name)s - %(levelname)s - %(message)s  
  28. datefmt=  

在指定handler的配置时,class是具体的handler类的类名,可以是相对logging模块或是全路径类名,比如需要RotatingFileHandler,则class的值可以为:RotatingFileHandler或者logging.handlers.RotatingFileHandler。args就是要传给这个类的构造方法的参数,就是一个元组,按照构造方法声明的参数的顺序。

 

运行结果,控制台输出:

2013-11-28 23:02:32,574 - logtest4.py:16 - tst - DEBUG - debug msg
2013-11-28 23:02:32,574 - logtest4.py:17 - tst - INFO - info msg
2013-11-28 23:02:32,574 - logtest4.py:18 - tst - WARNING - warn msg
2013-11-28 23:02:32,574 - logtest4.py:19 - tst - ERROR - error msg
2013-11-28 23:02:32,574 - logtest4.py:20 - tst - CRITICAL - critical msg

这里还要明确一点,logger对象是有继承关系的,比如名为a.b和a.c的logger都是名为a的子logger,并且所有的logger对象都继承于root。如果子对象没有添加handler等一些配置,会从父对象那继承。这样就可以通过这种继承关系来复用配置。


 

3. 多模块使用logging

logging模块保证在同一个python解释器内,多次调用logging.getLogger('log_name')都会返回同一个logger实例,即使是在多个模块的情况下。所以典型的多模块场景下使用logging的方式是在main模块中配置logging,这个配置会作用于多个的子模块,然后在其他模块中直接通过getLogger获取Logger对象即可。

这里使用上面配置文件:

 

  1. [loggers]  
  2. keys=root,main  
  3.   
  4. [handlers]  
  5. keys=consoleHandler,fileHandler  
  6.   
  7. [formatters]  
  8. keys=fmt  
  9.   
  10. [logger_root]  
  11. level=DEBUG  
  12. handlers=consoleHandler  
  13.   
  14. [logger_main]  
  15. level=DEBUG  
  16. handlers=fileHandler  
  17. qualname=main  
  18. #propagate=0  
  19.   
  20. [handler_consoleHandler]  
  21. class=StreamHandler  
  22. level=DEBUG  
  23. formatter=fmt  
  24. args=(sys.stdout,)  
  25.   
  26. [handler_fileHandler]  
  27. class=logging.handlers.RotatingFileHandler  
  28. level=DEBUG  
  29. formatter=fmt  
  30. args=('tst.log','a',20000,5,)  
  31.   
  32. [formatter_fmt]  
  33. format=%(asctime)s - %(filename)s:%(lineno)s - %(name)s - %(levelname)s - %(message)s  
  34. datefmt=  

主模块main.py:

 

 

  1. #!/usr/bin/python  
  2. # -*- coding:utf-8 -*-  
  3. #  
  4. # main.py  
  5. #  
  6. # ithomer.net  
  7.   
  8. import logging  
  9. import logging.config  
  10.   
  11.   
  12. logging.config.fileConfig('logging.conf')  
  13.   
  14. # root  
  15. logger_root = logging.getLogger('root')  
  16. logger_root.debug('debug root')  
  17.   
  18. # main  
  19. logger_main = logging.getLogger('main')  
  20. logger_main.info('info main')  
  21.   
  22. logger_main.info('start import module \'mod\'...')  
  23. import mod  
  24. logger_main.debug('test mod.testLogger()')  
  25. mod.testLogger()  
  26.   
  27. logger_root.info('the end!')  

 

子模块mod.py:

 

  1. #!/usr/bin/python  
  2. # -*- coding:utf-8 -*-  
  3. #  
  4. # mod.py  
  5. #  
  6. # ithomer.net  
  7.   
  8. import logging  
  9.   
  10. logger = logging.getLogger('main.mod')  
  11. logger.info('info of main.mod')  
  12.   
  13. def testLogger():  
  14.     logger.debug('this is main.mod testLogging()')  
  15.     logger.info('start import module \'submod\'...')  
  16.     import submod  
  17.     submod.testLogger()  

 

子子模块submod.py:

 

  1. #!/usr/bin/python  
  2. # -*- coding:utf-8 -*-  
  3. #  
  4. # submod.py  
  5. #  
  6. # ithomer.net  
  7.   
  8. import logging  
  9.   
  10. logger = logging.getLogger('main.mod.submod')  
  11. logger.info('info of main.mod.submod')  
  12.   
  13. def testLogger():  
  14.     logger.debug('this is main.mod.submod testLogging()')  

然后运行python main.py,控制台输出:

 

 

  1. 2013-11-28 16:58:15,517 - main.py:16 - root - DEBUG - debug root  
  2. 2013-11-28 16:58:15,517 - main.py:20 - main - INFO - info main  
  3. 2013-11-28 16:58:15,517 - main.py:22 - main - INFO - start import module 'mod'...  
  4. 2013-11-28 16:58:15,518 - mod.py:11 - main.mod - INFO - info of main.mod  
  5. 2013-11-28 16:58:15,518 - main.py:24 - main - DEBUG - test mod.testLogger()  
  6. 2013-11-28 16:58:15,518 - mod.py:14 - main.mod - DEBUG - this is main.mod testLogging()  
  7. 2013-11-28 16:58:15,519 - mod.py:15 - main.mod - INFO - start import module 'submod'...  
  8. 2013-11-28 16:58:15,519 - submod.py:11 - main.mod.submod - INFO - info of main.mod.submod  
  9. 2013-11-28 16:58:15,519 - submod.py:14 - main.mod.submod - DEBUG - this is main.mod.submod testLogging()  
  10. 2013-11-28 16:58:15,519 - main.py:27 - root - INFO - the end!  

 

可以看出,和预想的一样,然后在看一下tst.log,logger配置中的输出的目的地:

 

  1. 2013-11-28 16:58:15,517 - main.py:20 - main - INFO - info main  
  2. 2013-11-28 16:58:15,517 - main.py:22 - main - INFO - start import module 'mod'...  
  3. 2013-11-28 16:58:15,518 - mod.py:11 - main.mod - INFO - info of main.mod  
  4. 2013-11-28 16:58:15,518 - main.py:24 - main - DEBUG - test mod.testLogger()  
  5. 2013-11-28 16:58:15,518 - mod.py:14 - main.mod - DEBUG - this is main.mod testLogging()  
  6. 2013-11-28 16:58:15,519 - mod.py:15 - main.mod - INFO - start import module 'submod'...  
  7. 2013-11-28 16:58:15,519 - submod.py:11 - main.mod.submod - INFO - info of main.mod.submod  
  8. 2013-11-28 16:58:15,519 - submod.py:14 - main.mod.submod - DEBUG - this is main.mod.submod testLogging()  

tst.log中没有root logger输出的信息,因为logging.conf中配置了只有main logger及其子logger使用RotatingFileHandler,而root logger是输出到标准输出。

 

 

 

1、从一个使用场景开始

开发一个日志系统, 既要把日志输出到控制台, 还要写入日志文件

 

  1. #!/usr/bin/python  
  2. # ithomer in 2013  
  3.   
  4. import logging  
  5.   
  6. # create instance of logging  
  7. logger = logging.getLogger('mylogger')  
  8. logger.setLevel(logging.DEBUG)  
  9.   
  10.   
  11. # file handler  
  12. fh = logging.FileHandler('test.log')  
  13. fh.setLevel(logging.DEBUG)  
  14.   
  15.   
  16. # console handler  
  17. ch = logging.StreamHandler()  
  18. ch.setLevel(logging.DEBUG)  
  19.   
  20.   
  21. # formatter  
  22. fmt = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s')  
  23. fh.setFormatter(fmt)  
  24. ch.setFormatter(fmt)  
  25.   
  26.   
  27. # add formatter to handler  
  28. logger.addHandler(fh)  
  29. logger.addHandler(ch)  
  30.   
  31.   
  32. # print a log  
  33. logger.info('ithomer')  

运行后, 在控制台和日志文件(test.log)都有一条日志:

 

2013-11-27 23:45:20,329 - mylogger - INFO - ithomer

 

 

2、logging模块的API

结合上面的例子,我们说下几个最常使用的API

logging.getLogger([name])
返回一个logger实例,如果没有指定name,返回root logger。只要name相同,返回的logger实例都是同一个而且只有一个,即name和logger实例是一一对应的。这意味着,无需把logger实例在各个模块中传递。只要知道name,就能得到同一个logger实例
 
Logger.setLevel(lvl)
设置logger的level, level有以下几个级别:
>>> import logging
>>> print logging.NOTSET
0
>>> print logging.DEBUG
10
>>> print logging.INFO
20
>>> print logging.WARNING
30
>>> print logging.ERROR
40
>>> print logging.CRITICAL
50
NOTSET < DEBUG < INFO < WARNING < ERROR < CRITICAL
 

如果把looger的级别设置为INFO, 那么小于INFO级别的日志都不输出, 大于等于INFO级别的日志都输出

logger.debug("foobar")        # 不输出   
logger.info("foobar")            # 输出  
logger.warning("foobar")    # 输出  
logger.error("foobar")          # 输出  
logger.critical("foobar")       # 输出  

 
Logger.addHandler(hdlr)
logger可以雇佣handler来帮它处理日志, handler主要有以下几种:
StreamHandler         # 输出到控制台
FileHandler                # 输出到文件
handler还可以设置自己的level以及输出格式。
 
logging.basicConfig([**kwargs])
这个函数用来配置root logger, 为root logger创建一个StreamHandler,设置默认的格式。
这些函数: logging.debug()、logging.info()、logging.warning()、logging.error()、logging.critical() 如果调用的时候发现root logger没有任何 handler, 会自动调 basicConfig添加一个handler, 如果root logger已有handler, 这个函数不做任何事情,使用basicConfig来配置root logger的输出格式和level:
import logging  
logging.basicConfig(format='%(levelname)s:%(message)s', level=logging.DEBUG)  
logging.debug('This message should appear on the console')  

 

 

3、root logger与logger 父子关系

前面多次提到root logger, 实际上logger实例之间还有父子关系, root logger就是处于最顶层的logger, 它是所有logger的祖先。如下图:
root logger是默认的logger,如果不创建logger实例, 直接调用logging.debug()、logging.info()、logging.warning()、logging.error()、logging.critical()这些函数,那么使用的logger就是 root logger, 它可以自动创建,也是单实例的。
 
如何得到root logger
通过logging.getLogger()或者logging.getLogger("")得到root logger实例。
 
默认的level
root logger默认的level是logging.WARNING
 
如何表示父子关系
logger的name的命名方式可以表示logger之间的父子关系. 比如:
parent_logger = logging.getLogger('foo')
child_logger = logging.getLogger('foo.bar')
 
什么是effective level
logger有一个概念,effective level。 如果一个logger没有显示地设置level,那么它就用父亲的level。如果父亲也没有显示地设置level, 就用父亲的父亲的level,以此推....

最后到达root logger,一定设置过level。默认为logging.WARNING,child loggers得到消息后,既把消息分发给它的handler处理,也会传递给所有祖先logger处理,来看一个例子:

 

  1. #/usr/bin/python  
  2. # ithomer in 2013  
  3.   
  4. import logging  
  5.   
  6. # root logger  
  7. root = logging.getLogger()      # root  
  8.   
  9. ch = logging.StreamHandler()  
  10. ch.setLevel(logging.DEBUG)  
  11.   
  12. formatter = logging.Formatter('%(asctime)s - %(levelname)s - %(message)s')  
  13. ch.setFormatter(formatter)  
  14.   
  15. root.addHandler(ch)  
  16.   
  17.   
  18. # logging as parent  
  19. p = logging.getLogger('foo')  
  20. p.setLevel(logging.DEBUG)  
  21. ch = logging.StreamHandler()  
  22. ch.setLevel(logging.DEBUG)  
  23. formatter = logging.Formatter('%(asctime)s - %(message)s')  
  24. ch.setFormatter(formatter)  
  25. p.addHandler(ch)  
  26.   
  27.   
  28. # logging as child  
  29. c = logging.getLogger('foo.bar')  
  30. c.debug('foo')  

 

运行结果:

2013-11-27 22:40:56,699 - foo
2013-11-27 22:40:56,699 - DEBUG - foo

 
可见, 孩子logger没有任何handler,所以对消息不做处理,但是它把消息转发给了它的父亲以及root logger,最后输出两条日志,分别是p和root 输出的logging。




 

 

参考推荐:

python的logging模块

Python日志系统Logging

python 日志模块 logging 详解

Python日志输出——logging模块