logging模块,还在使用print打印?

为什么使用日志

使用日志来看程序的输入,相比于print,多了一个层级的概念。并且可以将不同层级的日志信息,进行不同的处理。比如正常的debug信息,就可以正常记录到log文件中,供以后日志挖掘使用。critical级别的可能就需要发送一封邮件给运维人员,及时提醒。

日志的级别

日志一共分成5个等级,从低到高分别是:DEBUG INFO WARNING ERROR CRITICAL。

  • DEBUG:详细的信息,通常只出现在诊断问题上
  • INFO:确认一切按预期运行
  • WARNING:一个迹象表明,一些意想不到的事情发生了,或表明一些问题在不久的将来(例如。磁盘空间低”)。这个软件还能按预期工作。
  • ERROR:更严重的问题,软件没能执行一些功能
  • CRITICAL:一个严重的错误,这表明程序本身可能无法继续运行

默认的是WARNING,当在WARNING或之上时才被跟踪。

开发应用程序或部署开发环境时,可以使用DEBUG或INFO级别的日志获取尽可能详细的日志信息来进行开发或部署调试;
应用上线或部署生产环境时,应该使用WARNING或ERROR或CRITICAL级别的日志来降低机器的I/O压力和提高获取错误日志信息的效率。
日志级别的指定通常都是在应用程序的配置文件中进行指定的。

logging模块的简单使用

打印日志信息到屏幕上

这其实是开发过程中,最简单的一项需求。并且可以通过这个取代print。

1
2
3
4
5
6
7
import logging

logging.debug('debug message')
logging.info('info message')
logging.warning('warning message')
logging.critical('citical message')
logging.error('error message')

输出为:

1
2
3
WARNING:root:warning message
CRITICAL:root:citical message
ERROR:root:error message

可以看到只用warning以上的日志被打印出来了,而且默认的日志格式为:

1
日志级别:Logger名称:用户输出消息。

打印日志到文件中

一般详细的日志都会存入日志文件中,本次实现需要另外开启一个python解释器。

1
2
3
4
5
6
7
8
9
10
11
12
13
14

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='test.log',
filemode='w')

logging.debug('debug message')
logging.info('info message')
logging.warning('warning message')
logging.critical('citical message')
logging.error('error message')

下面执行

cat test.log

可以得到日志的输出

1
2
3
4
5
一, 02 10 2017 16:47:19 test.py[line:17] DEBUG debug message
一, 02 10 2017 16:47:19 test.py[line:18] INFO info message
一, 02 10 2017 16:47:19 test.py[line:19] WARNING warning message
一, 02 10 2017 16:47:19 test.py[line:20] CRITICAL citical message
一, 02 10 2017 16:47:19 test.py[line:21] ERROR error message

下面有几点basicConfig参数说明 :
level:只用大于等于日志级别的日志才会被处理
format:输出日志的格式
具体格式如下:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
%(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用户输出的消息

datefmt:时间的格式

打印日志既到屏幕上又打印到文件中

这就需要引入logger对象的概念,实际上原先直接使用logging是相当远使用一个默认的logger,名字为root。所以原先两次实验,需要使用两个python解释器来分别执行,因为都是使用了一个root的logger。

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
import logging

# 第一步,创建一个logger
logger = logging.getLogger()
logger.setLevel(logging.DEBUG) # logger的总开关,只有大于Debug的日志才能被logger对象处理


# 第二步,创建一个handler,用于写入日志文件
file_handler = logging.FileHandler('test.log',mode='w')
file_handler.setLevel(logging.INFO) # 输出到file的log等级的开关
# 创建该handler的formatter
file_handler.setFormatter(
logging.Formatter(
fmt='%(asctime)s - %(filename)s[line:%(lineno)d] - %(levelname)s: %(message)s',
datefmt='%Y-%m-%d %H:%M:%S')
)
# 添加handler到logger中
logger.addHandler(file_handler)

# 第三步,创建一个handler,用于输出到控制台
console_handler = logging.StreamHandler()
console_handler.setLevel(logging.CRITICAL) # 输出到控制台的log等级的开关
# 创建该handler的formatter
console_handler.setFormatter(
logging.Formatter(
fmt='%(asctime)s - %(levelname)s: %(message)s',
datefmt='%Y-%m-%d %H:%M:%S')
)
logger.addHandler(console_handler)

#日志
logger.debug('this is a logger debug message')
logger.info('this is a logger info message')
logger.warning('this is a logger warning message')
logger.error('this is a logger error message')
logger.critical('this is a logger critical message')

所以使用logger对象可以分为几个步骤:先创建一个logger对象,并指定其level,否则默认为warning。然后再创建需要的handler对象,并设置level和format,然后添加到logger对象中。

logging库采取了模块化的设计,提供了许多组件:记录器、处理器、过滤器和格式化器。
Logger 暴露了应用程序代码能直接使用的接口。
Filter提供了更好的粒度控制,它可以决定输出哪些日志记录。
Handler将(记录器产生的)日志记录发送至合适的目的地。
Formatter 指明了最终输出中日志记录的布局。

更多的handler

比如可以通过邮件发送紧急的日志

1
2
3
4
5
6
mail_handler = logging.handlers.SMTPHandler(
mailhost='smtp.163.com',
fromaddr='nghuyong@163.com',
toaddrs='1013975672@qq.com',
subject='这是一封运维发送的邮件',
credentials=('acconut','password'))

logging在多模块中的使用

logging模块保证在同一个python解释器内,多次调用logging.getLogger(‘log_name’)都会返回同一个logger实例,即使是在多个模块的情况下。

所以典型的多模块场景下使用logging的方式是在main模块中配置logging,这个配置会作用于多个的子模块,然后在其他模块中直接通过getLogger获取Logger对象即可。
通过logger的命名也能体现出logger的树形结构。

handlers.py

1
2
3
4
5
6
7
8
9
import logging
console_handler = logging.StreamHandler()
console_handler.setLevel(logging.DEBUG) # 输出到控制台的log等级的开关
# 创建该handler的formatter
console_handler.setFormatter(
logging.Formatter(
fmt='%(asctime)s - %(name)s - %(levelname)s: %(message)s',
datefmt='%H:%M:%S')
)

main.py

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
import logging
from handlers import console_handler

root_logger = logging.getLogger('root')
root_logger.setLevel(logging.INFO)


root_logger.addHandler(console_handler)
root_logger.info('root logger begin')

logger = logging.getLogger('root.main')
logger.setLevel(logging.DEBUG)
logger.addHandler(console_handler)
logger.debug('main logger begin')

import mod
logger.debug('let\'s test mod.testLogger()')
mod.testLogger()

logger.debug('main logger end')
root_logger.info('root logger end')

mod.py

1
2
3
4
5
6
7
8
9
10
import logging
from handlers import console_handler

logger = logging.getLogger('root.main.mod')
logger.setLevel(logging.DEBUG)
logger.addHandler(console_handler)
logger.debug('mod logger begin')

def testLogger():
logger.debug('this is testlogger')

运行main.py输出为:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
18:17:07 - root - INFO: root logger begin
18:17:07 - root.main - DEBUG: main logger begin
18:17:07 - root.main - DEBUG: main logger begin
18:17:07 - root.main.mod - DEBUG: mod logger begin
18:17:07 - root.main.mod - DEBUG: mod logger begin
18:17:07 - root.main.mod - DEBUG: mod logger begin
18:17:07 - root.main - DEBUG: let's test mod.testLogger()
18:17:07 - root.main - DEBUG: let's test mod.testLogger()
18:17:07 - root.main.mod - DEBUG: this is testlogger
18:17:07 - root.main.mod - DEBUG: this is testlogger
18:17:07 - root.main.mod - DEBUG: this is testlogger
18:17:07 - root.main - DEBUG: main logger end
18:17:07 - root.main - DEBUG: main logger end
18:17:07 - root - INFO: root logger end

可以看到存在层级关系,子logger的日子还会交给祖辈logger的handler进行处理。

具体logger处理的流程图: