logging模块学习

logging模块：

https://docs.python.org/3/howto/logging.html#logging-basic-tutorial

本记录教程

日志记录是一种跟踪某些软件运行时发生的事件的方法。该软件的开发人员将日志调用添加到其代码中，以指示已发生某些事件。事件由描述性消息描述，该消息可以可选地包含变量数据（即，每次事件发生时都可能不同的数据）。事件也具有开发者认为该事件的重要性。重要性也可以称为水平 或严重性。

当使用日志

日志记录提供了一组便利功能，用于简单的日志记录用法。这是debug()，info()，warning()，error()和critical()。要确定何时使用日志记录，请参见下表，该表针对一组常见任务中的每个状态，指出了用于日志记录的最佳工具。

您要执行的任务	完成任务的最佳工具
显示控制台输出，用于命令行脚本或程序的常规使用	print()
报告程序正常运行期间发生的事件（例如，用于状态监视或故障调查）	logging.info()（或 logging.debug()用于诊断目的的非常详细的输出）
发出有关特定运行时事件的警告	warnings.warn() 在库代码中，如果可以避免出现此问题，则应修改客户端应用程序以消除警告 logging.warning() 如果客户端应用程序无法处理这种情况，但仍应注意该事件
报告有关特定运行时事件的错误	引发异常
报告抑制错误而不会引发异常（例如，长时间运行的服务器进程中的错误处理程序）	logging.error()， logging.exception()或logging.critical()适用于特定的错误和应用程序域

日志记录功能以它们用来跟踪的事件的级别或严重性命名。下面描述了标准级别及其适用性（按照严重程度从高到低的顺序）：

水平	使用时
DEBUG	详细信息，通常仅在诊断问题时才需要。
INFO	确认一切正常。
WARNING	表示发生了意外情况，或者表示在不久的将来出现了一些问题（例如“磁盘空间不足”）。该软件仍按预期运行。
ERROR	由于存在更严重的问题，该软件无法执行某些功能。
CRITICAL	严重错误，表明程序本身可能无法继续运行。

默认级别为WARNING，这意味着将仅跟踪此级别及更高级别的事件，除非将日志记录程序包配置为执行其他操作。

跟踪的事件可以以不同的方式处理。处理跟踪事件的最简单方法是将它们打印到控制台。另一种常见的方法是将它们写入磁盘文件。

测试0：默认输出到屏幕

import logging

logging.warning("Watch out!")
logging.info(" OK ")

如果将这些行输入脚本并运行，您将看到：

WARNING:root:Watch out!
打印在控制台上。该INFO消息未出现，因为默认级别为WARNING。打印的消息包括级别指示和在记录调用中提供的事件描述，即“当心！”。现在不必担心“root”部分：稍后将进行解释。如果需要，可以非常灵活地格式化实际输出；格式化选项也将在后面说明。

测试1：记录到文件

一种非常常见的情况是将日志记录事件记录在文件中，因此接下来让我们看一下。

确保在新启动的Python解释器中尝试以下操作:。

import logging

logging.basicConfig(filename="testlog1.log", level=logging.DEBUG)
logging.debug("This message should go to zhe log file")
logging.info("This is logging info  std out ")
logging.warning('And this is Warning out')

打开testlog1.log文件查看内容

DEBUG:root:This message should go to zhe log file
INFO:root:This is logging info  std out 
WARNING:root:And this is Warning out

此示例还显示了如何设置用作跟踪阈值的日志记录级别。在这种情况下，因为我们将阈值设置为 DEBUG，所以所有消息都已打印。

测试2：如果要从命令行选项设置日志记录级别，例如：--log=INFO

import  logging
import argparse

# assuming loglevel is bound to the string value obtained from the
# command line argument. Convert to upper case to allow the user to
# specify --log=DEBUG or --log=debug

parser = argparse.ArgumentParser("指定日志级别")
parser.add_argument("-l","--log",default="INFO")
args = parser.parse_args()
cmd_level = args.log
loglevel = getattr(logging, cmd_level.upper(), None)

print("获取到命令行输入的日志级别：%d" % loglevel)
if not isinstance(loglevel,int):
    raise ValueError('Invalid log level: %s' % loglevel)

然后在命令行执行：

 python3 python set_loglevel_from_cmd.py  --log=INFO
获取到命令行输入的日志级别：20

日志同样被写入到文件中，查看记录的文件内容

INFO:root:This is logging info  std out 
WARNING:root:And this is Warning out
INFO:root:This is logging info  std out 


测试3将日志内容加入变量：

import logging

logging.warning("%s 找不到 %s", "儿子", "爸爸")

输出 

WARNING:root:儿子 找不到 爸爸

测试4：更改显示消息的格式：时间、变量等

要更改用于显示消息的格式，您需要指定要使用的格式：

格式变量常用的有：

　　时间：%(asctime)s  

　　级别：%(levelname)s

　　产生日志的文件名：%(filename)s

　　产生日志的代码所在行数：%(lineno)d

　　日志文本内容：%(message)s

　　更多参见：https://docs.python.org/3/library/logging.html#logrecord-attributes

　　测试代码如下：

import  logging
logging.basicConfig(
    # 日志格式
    format='%(asctime)s  %(levelname)s %(filename)s[line:%(lineno)d] %(message)s ',
    # 配置日志中时间格式
    datefmt='%Y-%m-%d %H:%M:%S',
    # 配置日志文件名
    filename='format_log.txt',
    # 配置日志模式，默认为追加写入
    filemode='a',
    # 配置日志记录 的级别
    level=logging.INFO
)
logging.info("test info level logging format to file")

示例记录

2020-07-06 17:04:02  INFO logformat_test.py[line:22] test info level logging format to file 

高级日志教程

日志记录库采用模块化方法，并提供了几类组件：记录器，处理程序，过滤器和格式化程序。

• 记录器公开了应用程序代码直接使用的接口。

• 处理程序将日志记录（由记录器创建）发送到适当的目的地。

• 筛选器提供了更细粒度的功能，用于确定要输出的日志记录。

• 格式化程序在最终输出中指定日志记录的布局。

日志事件信息在LogRecord实例中的记录器，处理程序，过滤器和格式化程序之间传递。

通过在Logger 类的实例上调用方法（以下称为loggers）来执行日志记录。每个实例都有一个名称，并且在概念上使用点（句点）作为分隔符将它们排列在命名空间层次结构中。例如，名为“ scan”的记录器是“ scan.text”，“ scan.html”和“ scan.pdf”记录器的父级。记录器名称可以是您想要的任何名称，并指示记录消息来源的应用程序区域。

命名记录器时，一个好的习惯是在每个使用日志记录的模块中使用模块级记录器，命名如下：

logger = logging.getLogger(__name__)

这意味着记录器名称跟踪程序包/模块的层次结构，并且从记录器名称中记录事件的地方很直观。

高级测试用例一：

import logging

# create logger and 设置日志服务名称
logger = logging.getLogger("TestSserviceName")
# 设置日志记录的级别
logger.setLevel(logging.DEBUG)

# create formatter
formatter = logging.Formatter('%(asctime)s %(name)s %(levelname)s %(filename)s[line:%(lineno)s] %(message)s' )

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

# add formatter to console_log
console_log.setFormatter(formatter)

# add console_log to logger
logger.addHandler(console_log)

# 'application' code 开始记录日志
logger.debug("debug Message....")
logger.info('info message')
logger.warning('warning message for test')
logger.error('error content for test')
logger.critical('critical message')

测试输出：

2020-07-06 20:09:02,827 TestSserviceName DEBUG getLogger方式创建日志记录实例.py[line:30] debug Message....
2020-07-06 20:09:02,828 TestSserviceName INFO getLogger方式创建日志记录实例.py[line:31] info message
2020-07-06 20:09:02,828 TestSserviceName WARNING getLogger方式创建日志记录实例.py[line:32] warning message for test
2020-07-06 20:09:02,828 TestSserviceName ERROR getLogger方式创建日志记录实例.py[line:33] error content for test
2020-07-06 20:09:02,828 TestSserviceName CRITICAL getLogger方式创建日志记录实例.py[line:34] critical message

高级测试用例二：多个处理程序和格式化（常用）

记录器是普通的Python对象。addHandler()对于您可以添加的处理程序数量，该方法没有最小或最大配额。有时，将应用程序将所有严重性的所有消息记录到文本文件，同时将错误或更高级别的消息记录到控制台将是有益的。要进行设置，只需配置适当的处理程序即可。应用程序代码中的日志记录调用将保持不变。这是对先前基于模块的简单配置示例的略微修改：

#!/usr/bin/env python3
# -*- coding:utf-8 -*-
#  @Time: 2020/7/6 20:23
#  @Author:zhangmingda
#  @File: 所有级别保存到文件_错误保存同时输出到屏幕.py
#  @Software: PyCharm
#  Description:

import logging

logger = logging.getLogger('TestService')
logger.setLevel(logging.DEBUG)

# create file handler which log even debug messages
fh = logging.FileHandler('Filehandler.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 handlers
formatter = logging.Formatter(
    '%(asctime)s %(name)s %(levelname)s %(message)s'
)
fh.setFormatter(formatter)
ch.setFormatter(formatter)

# add the handlers to logger
logger.addHandler(fh)
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')

你会发现，控制台输出只有

2020-07-06 20:32:59,757 TestService ERROR error message
2020-07-06 20:32:59,757 TestService CRITICAL critical message

日志文件中啥都有

2020-07-06 20:32:59,756 TestService DEBUG debug message
2020-07-06 20:32:59,756 TestService INFO info message
2020-07-06 20:32:59,757 TestService WARNING warn message
2020-07-06 20:32:59,757 TestService ERROR error message
2020-07-06 20:32:59,757 TestService CRITICAL critical message

高级测试用例三：记录多个服务名日志，格式化对齐字段（常用）

假设您要使用不同的消息格式和在不同的情况下登录控制台和文件。假设您要记录DEBUG或更高级别的消息到文件，而INFO或更高级别的消息记录到控制台。我们还假设该文件应包含时间戳，但控制台消息不应包含时间戳。这是实现此目的的方法：

#!/usr/bin/env python3
# -*- coding:utf-8 -*-
#  @Time: 2020/7/6 20:41
#  @Author:zhangmingda
#  @File: 多个服务日志.py
#  @Software: PyCharm
#  Description:

import logging
# set up loggging to file - see previous section for more details
logging.basicConfig(
    level=logging.DEBUG,
    format='%(asctime)s %(name)-12s %(levelname)-8s %(message)s',
    datefmt='%Y-%m-%d %H:%M:%S',
    filename='format_more_service_test.log',
    filemode='a'
)

# define a Handler which writes INFO messages or higher to the sys.stderr
console = logging.StreamHandler()
console.setLevel(logging.INFO)
console_log_formatter = logging.Formatter('%(name)-12s: %(levelname)-8s %(message)s')

# tell the hanler to use this format
console.setFormatter(console_log_formatter)

# add handler to the root logger
logging.getLogger('').addHandler(console)

# Now ,we can log to the root looger ,or any other logger ,First the root
logging.info("this is test Info log from zhangmingda")

# Now, define a couple of other loggers which might represent areas in your
# application:

logger1 = logging.getLogger('myapp.area1')
logger2 = logging.getLogger('myapp.area2')

logger1.debug('Quick zephyrs blow, vexing daft Jim.')
logger1.info('How quickly daft jumping zebras vex.')
logger2.warning('Jail zesty vixen who grabbed pay from quack.')
logger2.error('The five boxing wizards jump quickly.')

控制台输出

root : INFO this is test Info log from zhangmingda
myapp.area1 : INFO How quickly daft jumping zebras vex.
myapp.area2 : WARNING Jail zesty vixen who grabbed pay from quack.
myapp.area2 : ERROR The five boxing wizards jump quickly.

日志文件内存储

2020-07-06 20:50:41 root         INFO     this is test Info log from zhangmingda
2020-07-06 20:50:41 myapp.area1  DEBUG    Quick zephyrs blow, vexing daft Jim.
2020-07-06 20:50:41 myapp.area1  INFO     How quickly daft jumping zebras vex.
2020-07-06 20:50:41 myapp.area2  WARNING  Jail zesty vixen who grabbed pay from quack.
2020-07-06 20:50:41 myapp.area2  ERROR    The five boxing wizards jump quickly.

 高级测试用例四：使用配置文件方式，配置日志

这是logging.conf配置文件：

[loggers]
keys=root,testService

[handlers]
keys=consoleHandler,fileHandler

[formatters]
keys=defaultFormatter


[logger_root]
level=DEBUG
handlers=consoleHandler,fileHandler

[logger_testService]
level=DEBUG
handlers=fileHandler
qualname=testServiceFromZmd
propagate=0


[handler_consoleHandler]
class=StreamHandler
level=ERROR
formatter=defaultFormatter
args=(sys.stdout,)

[handler_fileHandler]
class=logging.handlers.RotatingFileHandler
level=DEBUG
formatter=defaultFormatter
args=('logging.conf.log',)

[formatter_defaultFormatter]
format=%(asctime)s - %(name)8s - %(levelname)8s - %(message)s

#更多配置文件格式参见：https://docs.python.org/3/library/logging.config.html#logging-config-fileformat

导入配置文件配置logger

import logging
import logging.config

logging.config.fileConfig('logging.conf')

# create logger
logger = logging.getLogger('simpleExample')

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

屏幕输出错误

2020-07-07 11:21:32,393 - testService - ERROR - error message
2020-07-07 11:21:32,393 - testService - CRITICAL - critical message

 日志记录DEBUG

2020-07-07 11:21:32,392 - testService -    DEBUG - debug message
2020-07-07 11:21:32,392 - testService -     INFO - info message
2020-07-07 11:21:32,393 - testService -  WARNING - warn message
2020-07-07 11:21:32,393 - testService -    ERROR - error message
2020-07-07 11:21:32,393 - testService - CRITICAL - critical message

配置日志服务器示例，可以用来接收网络传来的日志进行存储

这是使用日志记录配置服务器的模块示例：

服务端默认TCP的9020端口：

#!/usr/bin/env python3
# -*- coding:utf-8 -*-
#  @Time: 2020/7/6 20:57
#  @Author:zhangmingda
#  @File: 日志服务器监听端口.py
#  @Software: PyCharm
#  Description:
import pickle
import logging
import logging.handlers
import socketserver
import struct


class LogRecordStreamHandler(socketserver.StreamRequestHandler):
    """Handler for a streaming logging request.

    This basically logs the record using whatever logging policy is
    configured locally.
    """

    def handle(self):
        """
        Handle multiple requests - each expected to be a 4-byte length,
        followed by the LogRecord in pickle format. Logs the record
        according to whatever policy is configured locally.
        """
        while True:
            chunk = self.connection.recv(4)
            if len(chunk) < 4:
                break
            slen = struct.unpack('>L', chunk)[0]
            chunk = self.connection.recv(slen)
            while len(chunk) < slen:
                chunk = chunk + self.connection.recv(slen - len(chunk))
            obj = self.unPickle(chunk)
            record = logging.makeLogRecord(obj)
            self.handleLogRecord(record)

    def unPickle(self, data):
        return pickle.loads(data)

    def handleLogRecord(self, record):
        # if a name is specified, we use the named logger rather than the one
        # implied by the record.
        if self.server.logname is not None:
            name = self.server.logname
        else:
            name = record.name
        logger = logging.getLogger(name)
        # N.B. EVERY record gets logged. This is because Logger.handle
        # is normally called AFTER logger-level filtering. If you want
        # to do filtering, do it at the client end to save wasting
        # cycles and network bandwidth!
        logger.handle(record)

class LogRecordSocketReceiver(socketserver.ThreadingTCPServer):
    """
    Simple TCP socket-based logging receiver suitable for testing.
    """

    allow_reuse_address = True

    def __init__(self, host='localhost',
                 port=logging.handlers.DEFAULT_TCP_LOGGING_PORT,
                 handler=LogRecordStreamHandler):
        socketserver.ThreadingTCPServer.__init__(self, (host, port), handler)
        self.abort = 0
        self.timeout = 1
        self.logname = None

    def serve_until_stopped(self):
        import select
        abort = 0
        while not abort:
            rd, wr, ex = select.select([self.socket.fileno()],
                                       [], [],
                                       self.timeout)
            if rd:
                self.handle_request()
            abort = self.abort

def main():
    logging.basicConfig(
        format='%(relativeCreated)5d %(name)-15s %(levelname)-8s %(message)s')
    tcpserver = LogRecordSocketReceiver()
    print('About to start TCP server...')
    tcpserver.serve_until_stopped()

if __name__ == '__main__':
    main()

客户端发送日志

#!/usr/bin/env python3
# -*- coding:utf-8 -*-
#  @Time: 2020/7/6 20:58
#  @Author:zhangmingda
#  @File: 日志服务器测试用客户端.py
#  @Software: PyCharm
#  Description:

import logging, logging.handlers

rootLogger = logging.getLogger('')
rootLogger.setLevel(logging.DEBUG)
socketHandler = logging.handlers.SocketHandler('localhost',
                    logging.handlers.DEFAULT_TCP_LOGGING_PORT)
# don't bother with a formatter, since a socket handler sends the event as
# an unformatted pickle
rootLogger.addHandler(socketHandler)

# Now, we can log to the root logger, or any other logger. First the root...
logging.info('Jackdaws love my big sphinx of quartz.')

# Now, define a couple of other loggers which might represent areas in your
# application:

logger1 = logging.getLogger('myapp.area1')
logger2 = logging.getLogger('myapp.area2')

logger1.debug('Quick zephyrs blow, vexing daft Jim.')
logger1.info('How quickly daft jumping zebras vex.')
logger2.warning('Jail zesty vixen who grabbed pay from quack.')
logger2.error('The five boxing wizards jump quickly.')

客户端无输出；服务端输出如下

About to start TCP server...
32 root INFO Jackdaws love my big sphinx of quartz.
1065 myapp.area1 DEBUG Quick zephyrs blow, vexing daft Jim.
1066 myapp.area1 INFO How quickly daft jumping zebras vex.
1066 myapp.area2 WARNING Jail zesty vixen who grabbed pay from quack.
1066 myapp.area2 ERROR The five boxing wizards jump quickly.