Python-logging模块定制格式描述符实现定长日志等级

Python-logging模块定制格式描述符实现定长日志等级

前言

在写我自己的练手项目的时候,需要写一系列Python脚本来帮助我进行运维/环境配置,我希望这些脚本能够有比较好的日志记录。

上一篇博客中,我实现了日志同时向控制台和日志中进行输出,并且二者的日志等级、日志格式不相同。

但是,仍旧存在一个让我极其难受的问题:日志的等级是不定长的。大概看起来长这样:

2021-08-28 20:37:48,430 [DEBUG] code.31 __main__:	debug
2021-08-28 20:37:48,430 [INFO] code.32 __main__:	info
2021-08-28 20:37:48,430 [WARNING] code.33 __main__:	warning
2021-08-28 20:37:48,431 [CRITICAL] code.34 __main__:	critical

可给我恶心坏了,所以我希望能够将其长度改为定长的。

本博客中,我通过自定义日志的格式描述符,实现了定长的日志等级。

参考

解决思路

我现在使用的格式化字符串为:

'%(asctime)s [%(levelname)s] %(module)s.%(lineno)d %(name)s:\t%(message)s'
'[%(asctime)s %(levelname)s] %(message)s'

第一个是向文件写入的格式,第二个是向控制台输出的格式。可见,格式化字符串通过asctimelevelname等名称来指定当前占位的应该是什么内容。那我们可不可以自定义一个shortlevelname,将原先不等长的DEBUGINFOWARNINGCRITICAL映射为等长的DBGINFWARERR呢?

Filter

关于为日志格式添加新的格式描述符,官方提供了专门的接口Filter

其使用方法参见Python 官方文档 | 利用 Filter 传递上下文信息

Filter已经很好用了,官方文档也给出了很好的示例,这已经足以应对大多数情况了。

但是使用Filter有一个问题,它没法像handler一样,可以通过logging.basicConfig设置全局的默认配置,使用Filter需要先通过logging.getLogger()来获取一个logger实例,然后通过logger.setFilter()方法来设置Filter,每一次我们创建新的logger都需要进行这样的步骤,这未免有些麻烦。

LogRecord

通过Python官方文档|LogRecord,我们可以发现,我们在格式字符串中使用的格式描述符,其实对应的是LogRecord的属性的名字。所以,只要我们有办法在LogRecord被转换为字符串之前,为其添加我们需要的shortlevelname属性,也许就可以成功了。

关于修改LogRecord,有两个思路:

  1. 通过setLogRecordFactory()方法,使得LogRecord创建的时候就具有我们自定义的格式描述符;
  2. 继承Formatter,重写其format(record)方法,为record添加我们自定义的属性,然后调用super().format(record),在创建全局的handler后,调用handler.setFormatter()来将我们定义的子类传入;

第一种方法是整体的修改,而第二种方法可以进行更细粒度的控制。

这两种方法都利用了Python动态类型的特点——我们可以随时为一个对象添加新的属性。

实现

这里在原有代码的基础上进行修改(原有代码参见上一篇博客),通过在程序入口调用我们自定义的方法config_logging()来配置全局日志。

先把结果贴出来:

  1. 文件里长这样:
2021-08-28 22:43:37,953 [DBG] code.46 __main__:	debug
2021-08-28 22:43:37,954 [INF] code.47 __main__:	info
2021-08-28 22:43:37,954 [WAR] code.48 __main__:	warning
2021-08-28 22:43:37,954 [ERR] code.49 __main__:	critical
  1. 控制台长这样:
[2021/08/28 22:43:37 WAR] warning
[2021/08/28 22:43:37 ERR] critical
[2021/08/28 22:43:37 WAR] warning
[2021/08/28 22:43:37 ERR] critical

思路一、setLogRecordFactory

import logging
import sys

class ShortLevelNameLogFactory:
    def __init__(self, old_factory) -> None:
        self.old_factory = old_factory
        tmp = {
            "DEBUG": "DBG",
            "INFO": "INF",
            "WARNING": "WAR",
            "CRITICAL": "ERR"
        }
        self.levelname_trans = tmp # dict({v:v for v in tmp.values()}, **tmp)

    def __call__(self, name, level, fn, lno, msg, args, exc_info, func=None, sinfo=None, **kwargs)->logging.LogRecord:
        record = self.old_factory(name, level, fn, lno, msg, args, exc_info, func, sinfo, **kwargs)
        record.shortlevelname = self.levelname_trans[record.levelname]
        return record

def config_logging(file_name: str, console_level: int=logging.INFO, file_level: int=logging.DEBUG):
    old_factory = logging.getLogRecordFactory()
    new_factory = ShortLevelNameLogFactory(old_factory)
    logging.setLogRecordFactory(new_factory)
    
    file_handler = logging.FileHandler(file_name, mode='a', encoding="utf8")
    file_handler.setFormatter(logging.Formatter(
        '%(asctime)s [%(shortlevelname)s] %(module)s.%(lineno)d %(name)s:\t%(message)s'
        ))
    file_handler.setLevel(file_level)

    console_handler = logging.StreamHandler(sys.stdout)
    console_handler.setFormatter(logging.Formatter(
        '[%(asctime)s %(shortlevelname)s] %(message)s',
        datefmt="%Y/%m/%d %H:%M:%S"
        ))
    console_handler.setLevel(console_level)

    logging.basicConfig(
        level=min(console_level, file_level),
        handlers=[file_handler, console_handler],
        )

if __name__ == '__main__':
    config_logging("test.log", logging.WARNING, logging.DEBUG)
    logging.debug("debug")
    logging.info("info")
    logging.warning("warning")
    logging.critical("critical")

    logger = logging.getLogger(__name__)
    logger.debug("debug")
    logger.info("info")
    logger.warning("warning")
    logger.critical("critical")

思路二、继承Formatter

import logging
import sys

class ShortLevelNameFormatter(logging.Formatter):
    def __init__(self, *args, **kargs):
        super().__init__(*args, **kargs)
        tmp = {
            "DEBUG": "DBG",
            "INFO": "INF",
            "WARNING": "WAR",
            "CRITICAL": "ERR"
        }
        self.levelname_trans = tmp # dict({v:v for v in tmp.values()}, **tmp)

    def format(self, record: logging.LogRecord) -> str:
        record.shortlevelname = self.levelname_trans[record.levelname]
        return super().format(record)

def config_logging(file_name: str, console_level: int=logging.INFO, file_level: int=logging.DEBUG):
    file_handler = logging.FileHandler(file_name, mode='a', encoding="utf8")
    file_handler.setFormatter(ShortLevelNameFormatter(
        '%(asctime)s [%(shortlevelname)s] %(module)s.%(lineno)d %(name)s:\t%(message)s'
        ))
    file_handler.setLevel(file_level)

    console_handler = logging.StreamHandler(sys.stdout)
    console_handler.setFormatter(ShortLevelNameFormatter(
        '[%(asctime)s %(shortlevelname)s] %(message)s',
        datefmt="%Y/%m/%d %H:%M:%S"
        ))
    console_handler.setLevel(console_level)

    logging.basicConfig(
        level=min(console_level, file_level),
        handlers=[file_handler, console_handler],
        )

if __name__ == '__main__':
    config_logging("test.log", logging.WARNING, logging.DEBUG)
    logging.debug("debug")
    logging.info("info")
    logging.warning("warning")
    logging.critical("critical")

    logger = logging.getLogger(__name__)
    logger.debug("debug")
    logger.info("info")
    logger.warning("warning")
    logger.critical("critical")
posted @ 2021-08-28 21:32  SnowPhoenix  阅读(767)  评论(0编辑  收藏  举报