Python Tutorial

[TOC]

Logging Module

1、print log

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
#!/usr/locoal/bin/python
# -*- coding:utf-8 -*-

import logging

logging.basicConfig(level=logging.WARNING)
# 默认情况下,logging模块将日志打印到屏幕上(stdout),
# 日志级别为WARNING(即只有日志级别高于WARNING的日志信息才会输出)
# 日志级别大小关系为:CRITICAL > ERROR > WARNING > INFO > DEBUG > NOTSET

logging.debug('debug message')
logging.info('info message')
logging.warn('warn message')
logging.error('error message')
logging.critical('critical message')

输出:

1
2
3
WARNING:root:warn message
ERROR:root:error message
CRITICAL:root:critical message

debug和info级别低于WARNING,所以不会输出。

日志格式如下表格所示:

WARNING: root: warn message
日志级别: Logger实例名称: 日志内容

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

1
2
3
4
5
6
7
8
9
10
11
12
13
#!/usr/locoal/bin/python
# -*- coding:utf-8 -*-
import logging

logging.basicConfig(level=logging.DEBUG,
format='%(asctime)s %(filename)s[line:%(lineno)d] %(levelname)s %(message)s',
datefmt='%a, %d %b %Y %H:%M:%S',
filename='myapp.log',
filemode='w')

logging.debug('This is debug message')
logging.info('This is info message')
logging.warning('This is warning message')

myapp.log文件中内容为:

1
2
3
Sun, 24 May 2009 21:48:54 demo2.py[line:11] DEBUG This is debug message
Sun, 24 May 2009 21:48:54 demo2.py[line:12] INFO This is info message
Sun, 24 May 2009 21:48:54 demo2.py[line:13] WARNING This is warning message

**logging.basicConfig**函数各参数:

  • filename: 指定日志文件名
  • filemode: 和 file 函数意义相同,指定日志文件的打开模式,wa
  • 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或者File,默认输出到sys.stderr,当streamfilename同时指定时,stream被忽略。

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

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
#!/usr/locoal/bin/python
# -*- coding:utf-8 -*-
import logging

logging.basicConfig(level=logging.DEBUG,
format='%(asctime)s %(filename)s[line:%(lineno)d] %(levelname)s %(message)s',
datefmt='%a, %d %b %Y %H:%M:%S',
filename='myapp.log',
filemode='w')

#####################################################
#定义一个StreamHandler,将INFO级别或更高的日志信息打印到标准错误,并将其添加到当前的日志处理对象#
console = logging.StreamHandler()
console.setLevel(logging.INFO)
formatter = logging.Formatter('%(name)-12s: %(levelname)-8s %(message)s')
console.setFormatter(formatter)
logging.getLogger('').addHandler(console)
#####################################################

logging.debug('This is debug message')
logging.info('This is info message')
logging.warning('This is warning message')

屏幕上打印:

1
2
root        : INFO     This is info message
root : WARNING This is warning message

myapp.log文件中内容为:

1
2
3
Sun, 24 May 2009 21:48:54 demo2.py[line:11] DEBUG This is debug message
Sun, 24 May 2009 21:48:54 demo2.py[line:12] INFO This is info message
Sun, 24 May 2009 21:48:54 demo2.py[line:13] WARNING This is warning message

4、logging之日志循环(Rotating)

1
2
3
4
5
6
7
8
9
10
11
import logging
from logging.handlers import RotatingFileHandler

###################################################################################
#定义一个RotatingFileHandler,最多备份5个日志文件,每个日志文件最大10M
Rthandler = RotatingFileHandler('myapp.log', maxBytes=10*1024*1024,backupCount=5)
Rthandler.setLevel(logging.INFO)
formatter = logging.Formatter('%(name)-12s: %(levelname)-8s %(message)s')
Rthandler.setFormatter(formatter)
logging.getLogger('').addHandler(Rthandler)
###################################################################################

例3例4可以看出,logging有一个日志处理的主对象,其它处理方式都是通过addHandler添加进去的。
logging的几种handle方式如下:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
logging.StreamHandler: 日志输出到流,可以是sys.stderr、sys.stdout或者文件
logging.FileHandler: 日志输出到文件

日志回滚方式,实际使用时用 RotatingFileHandler 和 TimedRotatingFileHandler
logging.handlers.BaseRotatingHandler
logging.handlers.RotatingFileHandler
logging.handlers.TimedRotatingFileHandler

logging.handlers.SocketHandler: 远程输出日志到TCP/IP sockets
logging.handlers.DatagramHandler: 远程输出日志到UDP sockets
logging.handlers.SMTPHandler: 远程输出日志到邮件地址
logging.handlers.SysLogHandler: 日志输出到syslog
logging.handlers.NTEventLogHandler: 远程输出日志到Windows NT/2000/XP的事件日志
logging.handlers.MemoryHandler: 日志输出到内存中的制定buffer
logging.handlers.HTTPHandler: 通过"GET""POST"远程输出到HTTP服务器

由于StreamHandlerFileHandler是常用的日志处理方式,所以直接包含在logging模块中,而其他方式则包含在logging.handlers模块中,
上述其它处理方式的使用请参见python2.7手册!

5、通过logging.config模块配置日志

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
#logger.conf

##############################################

[loggers]
keys=root,example01,example02

[logger_root]
level=DEBUG
handlers=hand01,hand02

[logger_example01]
handlers=hand01,hand02
qualname=example01
propagate=0

[logger_example02]
handlers=hand01,hand03
qualname=example02
propagate=0

##############################################

[handlers]
keys=hand01,hand02,hand03

[handler_hand01]
class=StreamHandler
level=INFO
formatter=form02
args=(sys.stderr,)

[handler_hand02]
class=FileHandler
level=DEBUG
formatter=form01
args=('myapp.log', 'a')

[handler_hand03]
class=handlers.RotatingFileHandler
level=INFO
formatter=form02
args=('myapp.log', 'a', 10*1024*1024, 5)

##############################################

[formatters]
keys=form01,form02

[formatter_form01]
format=%(asctime)s %(filename)s[line:%(lineno)d] %(levelname)s %(message)s
datefmt=%a, %d %b %Y %H:%M:%S

[formatter_form02]
format=%(name)-12s: %(levelname)-8s %(message)s
datefmt=

例1:

1
2
3
4
5
6
7
8
9
10
11
12
#!/usr/locoal/bin/python
# -*- coding:utf-8 -*-

import logging
import logging.config

logging.config.fileConfig("logger.conf")
logger = logging.getLogger("example01")

logger.debug('This is debug message')
logger.info('This is info message')
logger.warning('This is warning message')

例2:

1
2
3
4
5
6
7
8
9
10
11
12
#!/usr/locoal/bin/python
# -*- coding:utf-8 -*-

import logging
import logging.config

logging.config.fileConfig("logger.conf")
logger = logging.getLogger("example02")

logger.debug('This is debug message')
logger.info('This is info message')
logger.warning('This is warning message')

6、logging是线程安全的

7. logging 重复写日志问题

用Python的logging模块记录日志时,遇到了重复记录日志的问题,第一条记录写一次,第二条记录写两次,第三条记录写三次….

原因:没有移除handler
解决:在日志记录完之后removeHandler

重复记录log的示例代码

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
#!/usr/locoal/bin/python
# -*- coding:utf-8 -*-
import logging

def log(message):
logger = logging.getLogger('testlog')
streamhandler = logging.StreamHandler()
streamhandler.setLevel(logging.ERROR)
formatter = logging.Formatter('%(asctime)s - %(levelname)s - %(name)s - %(message)s')
streamhandler.setFormatter(formatter)
logger.addHandler(streamhandler)
logger.error(message)

if __name__ == '__main__':
log("hi")
log("hi two")
log("hi three")

屏幕上打印:

1
2
3
4
5
6
2016-07-08 09:17:29,740 - ERROR - testlog - hi
2016-07-08 09:17:29,740 - ERROR - testlog - hi two
2016-07-08 09:17:29,740 - ERROR - testlog - hi two
2016-07-08 09:17:29,740 - ERROR - testlog - hi three
2016-07-08 09:17:29,740 - ERROR - testlog - hi three
2016-07-08 09:17:29,740 - ERROR - testlog - hi three

深度解析:

Google之后,大概搞明白了,就是你第二次调用log的时候,根据getLogger(name)里的name获取同一个logger,而这个logger里已经有了第一次你添加的handler,第二次调用又添加了一个handler,所以,这个logger里有了两个handler,所以输出log时就会输出两次;以此类推,调用几次就会有几个handler,有几个handler就会输出几次log……

所以这里有以下几个解决办法:

  1. 每次创建不同name的logger,每次都是新logger,不会有添加多个handler的问题。(这个办法太笨了,不符合我们这样优雅的coder)
  2. 每次记录完日志之后,调用**removeHandler()**把这个 logger 里的 handler 移除掉。
  3. 与方法2一样,不过把用 pop()loggerhandlers 列表里的handler 清空。
  4. 在log方法里做判断,如果这个 logger 已有 handler ,则不再添加 handler

修改后示例代码

方法2和3

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
#!/usr/locoal/bin/python
# -*- coding:utf-8 -*-
import logging

def log(message):
logger = logging.getLogger('testlog')
streamhandler = logging.StreamHandler()
streamhandler.setLevel(logging.ERROR)
formatter = logging.Formatter('%(asctime)s - %(levelname)s - %(name)s - %(message)s')
streamhandler.setFormatter(formatter)
logger.addHandler(streamhandler)
logger.error(message)

logger.removeHandler(streamhandler) # 方法2
# logger.handlers.pop() # 方法3
# logger.handlers = [] # 方法3

if __name__ == '__main__':
log("hi")
log("hi two")
log("hi three")

屏幕上打印:

1
2
3
2016-07-08 09:17:29,740 - ERROR - testlog - hi
2016-07-08 09:17:29,740 - ERROR - testlog - hi two
2016-07-08 09:17:29,740 - ERROR - testlog - hi three

方法4

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
#!/usr/locoal/bin/python
# -*- coding:utf-8 -*-
import logging

def log(message):
logger = logging.getLogger('testlog')

if not logger.handlers:
streamhandler = logging.StreamHandler()
streamhandler.setLevel(logging.ERROR)
formatter = logging.Formatter('%(asctime)s - %(levelname)s - %(name)s - %(message)s')
streamhandler.setFormatter(formatter)
logger.addHandler(streamhandler)

logger.error(message)


if __name__ == '__main__':
log("hi")
log("hi two")
log("hi three")