0%

Python_Logging

官方文档 知乎专栏

python 3.7

Logging是什么

Logging包是Python的标准包之一,可用于代码事件追踪.事件也是分等级的,一般而言不同类型的事件所采用的策略是不同的.

Logging提供的常用接口

Logging针对不同等级的事件,提供了以下默认接口:debug() , info() , warning() , error() , critical().以下的表格展示了代码中事件的级别以及相应的追踪方法:

追踪任务 推荐使用的工具
日常使用中展示控制台的输出 print()
日程程序操作中报告某事件的发生 logging.info()/logging.debug()
程序运行时提出警告信息 logging.warning()/warning.warn()
程序运行时出错 Raise exception
程序运行时出错不抛出异常 logging.error()/logging.exception()/logging.critical()

我们发现对于不同等级的事件,对应这不同的解决方式,其有不同的名称:比如:DEBUG,INFO等.这些名称的含义如下表展示:

Level When it’s used
DEBUG Detailed information, typically of interest only when diagnosing problems.
INFO Confirmation that things are working as expected.
WARNING An indication that something unexpected happened, or indicative of some problem in the near future (e.g. ‘disk space low’). The software is still working as expected.
ERROR Due to a more serious problem, the software has not been able to perform some function.
CRITICAL A serious error, indicating that the program itself may be unable to continue running.

看到这里应该对事件级别有了大概的认识,logging包中默认的追踪级别时DEBUG;

在日常使用时,我们最常用的事件追踪方式就两种:

  1. 打印到控制台;
  2. 写到硬盘文件中;

Logging的基本使用方式

代码示例

简单示例

直接调用logging.debug()等接口即可,在控制台输出对应格式;

1
2
3
4
5
import logging
logging.warning('Watch out!') # will print a message to the console
logging.info('I told you so') # will not print anything

# WARNING:root:Watch out!

上面代码只输出了warning()方法的信息,这是由于logging默认只追踪DEBUG(包括)之上的日志信息.

默认输出格式:

1
LEVEL:INFORMATION

我们发现相较于默认的输出格式,还有一个root被输出出来,这里的root指的时logger的层次.

输出到文件示例

1
2
3
4
5
import logging
logging.basicConfig(filename='example.log',level=logging.DEBUG)
logging.debug('This message should go to the log file')
logging.info('So should this')
logging.warning('And this, too')

输出文件内容:

1
2
3
DEBUG:root:This message should go to the log file
INFO:root:So should this
WARNING:root:And this, too

通过设置basicConfig()进行相关设置,细节这里不写;

更改文件的输出格式:format关键字

1
2
3
4
5
import logging
logging.basicConfig(format='%(levelname)s:%(message)s', level=logging.DEBUG)
logging.debug('This message should appear on the console')
logging.info('So should this')
logging.warning('And this, too')

输出内容:

1
2
3
DEBUG:This message should appear on the console
INFO:So should this
WARNING:And this, too

添加时间到输出格式中:%(asctime)s

1
2
3
import logging
logging.basicConfig(format='%(asctime)s %(message)s')
logging.warning('is when this event was logged.')

输出内容;

1
2010-12-12 11:41:42,612 is when this event was logged.

定制时间格式:datafmt关键字

1
2
3
import logging
logging.basicConfig(format='%(asctime)s %(message)s', datefmt='%m/%d/%Y %I:%M:%S %p')
logging.warning('is when this event was logged.')

输出内容:

1
12/12/2010 11:46:36 AM is when this event was logged.

format参数

在logging.basicConfig()方法内,format起着调整输出格式的作用.岂可选参数如下:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
`%(asctime)s`    表示当前时间,格式为`2018-07-01 19:08:41,050`,逗号后面是毫秒
`%(levelname)s` 表示日志级别名称
`%(message)s` 表示日志内容
`%(name)s` 表示日志名称(未指定则为roots)
`%(lineno)d` 表示输出日志的代码所在行数
`%(levelno)s` 表示数字形式的日志级别
`%(pathname)s` 表示程序执行路径,相当于`sys.argv[0]`
`%(filename)s` 表示所在文件名称
`%(funcName)s` 表示所在函数名称
`%(thread)d` 表示当前线程ID
`%(threadName)s` 表示当前线程名称
`%(process)d` 表示当前进程ID
`%(processName)s`表示当前进程名称
`%(module)s` 表示当前模块名称
`%(created)f` 表示UNIX标准时间浮点数表示

datefmt对时间格式进行修改

使用例子如下

1
2
3
4
5
import logging
logging.basicConfig(level=logging.INFO,
format='%(asctime)s %(message)s',
datefmt='%a, %d %b %Y %H:%M:%S +0000')
logging.info('this is a info')

输出结果如下

1
Sun, 01 Jul 2018 19:19:00 +0000  this is a info

datefmt的格式可以参考官网表格

style

默认为%,可选{$,他们的使用方法分别如下

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
# %
import logging
logging.basicConfig(level=logging.INFO,
format='%(asctime)s %(message)s',
datefmt='%a, %d %b %Y %H:%M:%S +0000',
style='%')
logging.info('this is a info')

# {
import logging
logging.basicConfig(level=logging.INFO,
format='{asctime} {message}',
datefmt='%a, %d %b %Y %H:%M:%S +0000',
style='{')
logging.info('this is a info')

# $
import logging
logging.basicConfig(level=logging.INFO,
format='$asctime $message',
datefmt='%a, %d %b %Y %H:%M:%S +0000',
style='$')
logging.info('this is a info')

Logging的高级使用方式

高级模块无非是可以定制化log的生成,存储,具体格式等内容.上面的简单示例已经或多或少的有所触及,比如通过format关键字指定输出格式,通过filename关键字指定log存储文件地址,等等.

在logging中,分布有四个模块,每个模块都包含有特定的功能,分别是:logger,handler,filter,formatter;

模块解释

  • Loggers expose the interface that application code directly uses.
  • Handlers send the log records (created by loggers) to the appropriate destination.
  • Filters provide a finer grained facility for determining which log records to output.
  • Formatters specify the layout of log records in the final output.

Log事件信息会在上述四个模块间传递,最终得到你想要的log日志信息;

Logger

Logger对象是logging的核心对象,其任务可以简单的分为产生信息并传递给下一模块,具体有三:

  1. 提供了多种接口,用于运行时记录相关信息.这里说的接口与logging类一致:debug(),info(),warning(),error(),etc;
  2. Logger对象可以决定处理什么等级的信息,可以通过默认关键字(level)设置或者filter对象;
  3. Logger对象可以将日志信息**传递给相关对象(handler)**进行接下来的处理.

特点:

Logger对象通过名称标识层次,层次间用英文句号分割.例如有三个logger其名称分别为:foo , foo.bar , foo.bar.baz,其分别扮演祖先,父母,与儿子的角色.类似于继承的概念.

一般情况下以当前的模块名称作为logger名称,这也就对模块的规范进行要求.以下是示例:

1
logger = logging.getLogger(__name__)

常见方法:


  • Logger.setLevel():指定logger需要处理的最低层次信息;
  • Logger.addHandler() and Logger.removeHandler():添加与移除Handler对象
  • Logger.addFilter() and Logger.removeFilter():添加与移除Filter对象

上述三个方法均具有继承性;


  • Logger.debug(),Logger.info(),Logger.warning(),Logger.error(),Logger.critical():产生log信息的方法.其信息均为format string,可通过替代符号”%s,%d,%d”进行设置.
  • Logger.exception() creates a log message similar to Logger.error(). The difference is that Logger.exception() dumps a stack trace along with it. Call this method only from an exception handler.
  • Logger.log() takes a log level as an explicit argument. This is a little more verbose for logging messages than using the log level convenience methods listed above, but this is how to log at custom log levels.

  • getLogger():获得logger对象的方法,默认名称为root,可指定.

Handlers

Handlers用来对log进行特定的分派处理,例如将某类型log发送到邮箱或存储在特定文件内.一般情况一个logger对象可以添加多个Handlers对象.

常见方法:

  • setLevel():设定进行dispatch的最底层事件
  • setFormatter():为handler对象选定格式对象
  • addFilter()/removeFilter():配置过滤对象

Formatters

这里没看懂文档解释

示例

配置它们的流程是

  • 配置好的format设置到handler中
  • 配置好的handler添加到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
import logging

# create logger
logger = logging.getLogger('simple_example')
logger.setLevel(logging.DEBUG)

# create console handler and set level to debug
ch = logging.StreamHandler()
ch.setLevel(logging.DEBUG)

# create formatter
formatter = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s')

# add formatter to ch
ch.setFormatter(formatter)

# add ch to logger
logger.addHandler(ch)

# 'application' code
logger.debug('debug message')
logger.info('info message')
logger.warning('warn message')
logger.error('error message')
logger.critical('critical message')

运行结果

1
2
3
4
5
2005-03-19 15:10:26,618 - simple_example - DEBUG - debug message
2005-03-19 15:10:26,620 - simple_example - INFO - info message
2005-03-19 15:10:26,695 - simple_example - WARNING - warn message
2005-03-19 15:10:26,697 - simple_example - ERROR - error message
2005-03-19 15:10:26,773 - simple_example - CRITICAL - critical message

创建log流程的多种方式

这里不一一展示

  1. Creating loggers, handlers, and formatters explicitly using Python code that calls the configuration methods listed above.
  2. Creating a logging config file and reading it using the fileConfig() function.
  3. Creating a dictionary of configuration information and passing it to the dictConfig() function.

样例探究Logging的特点

样例地址 上述地址上讲解了各种情况下Logger的使用方式,不需要意义查看,针对自己的场景常看相关样例即可,这里仅介绍第一个样例.

多模块使用Logging的方式

  1. 模块名称标识Logger的方式,即使在不同模块我们使用相同的名称,也会获得相同的对象;
  2. 不同模块间建议使用层次化模块名称,名称层次使用句号分割,主模块采用作为父名称,副模块采用子名称.
  3. 子模块的调用会自动传给父模块;

module.py模块

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

# create logger with 'spam_application'
logger = logging.getLogger('spam_application')
logger.setLevel(logging.DEBUG)
# create file handler which logs even debug messages
fh = logging.FileHandler('spam.log')
fh.setLevel(logging.DEBUG)
# create console handler with a higher log level
ch = logging.StreamHandler()
ch.setLevel(logging.ERROR)
# create formatter and add it to the handlers
formatter = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s')
fh.setFormatter(formatter)
ch.setFormatter(formatter)
# add the handlers to the logger
logger.addHandler(fh)
logger.addHandler(ch)

logger.info('creating an instance of auxiliary_module.Auxiliary')
a = auxiliary_module.Auxiliary()
logger.info('created an instance of auxiliary_module.Auxiliary')
logger.info('calling auxiliary_module.Auxiliary.do_something')
a.do_something()
logger.info('finished auxiliary_module.Auxiliary.do_something')
logger.info('calling auxiliary_module.some_function()')
auxiliary_module.some_function()
logger.info('done with auxiliary_module.some_function()')

auxiliary_module.py辅助模块

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
import logging

# create logger
module_logger = logging.getLogger('spam_application.auxiliary')

class Auxiliary:
def __init__(self):
self.logger = logging.getLogger('spam_application.auxiliary.Auxiliary')
self.logger.info('creating an instance of Auxiliary')

def do_something(self):
self.logger.info('doing something')
a = 1 + 1
self.logger.info('done doing something')

def some_function():
module_logger.info('received a call to "some_function"')

输出结果:

1
2
3
4
5
6
7
8
9
10
11
2020-08-14 16:51:52,747 - spam_application - INFO - creating an instance of auxiliary_module.Auxiliary
2020-08-14 16:51:52,747 - spam_application.auxiliary.Auxiliary - INFO - creating an instance of Auxiliary
2020-08-14 16:51:52,747 - spam_application - INFO - created an instance of auxiliary_module.Auxiliary
2020-08-14 16:51:52,747 - spam_application - INFO - calling auxiliary_module.Auxiliary.do_something
2020-08-14 16:51:52,748 - spam_application.auxiliary.Auxiliary - INFO - doing something
2020-08-14 16:51:52,748 - spam_application.auxiliary.Auxiliary - INFO - done doing something
2020-08-14 16:51:52,748 - spam_application - INFO - finished auxiliary_module.Auxiliary.do_something
2020-08-14 16:51:52,748 - spam_application - INFO - calling auxiliary_module.some_function()
2020-08-14 16:51:52,748 - spam_application.auxiliary - INFO - received a call to "some_function"
2020-08-14 16:51:52,748 - spam_application - INFO - done with auxiliary_module.some_function()