如何在Python项目中插入日志

如何在Python项目中插入日志

可以说，python自带的标准日志库logging，是每个写python的程序员从新手小白到进阶小白（哈哈）必须会的。本文将介绍三个典型的场景，让你理解，什么时候应该使用日志，以及用哪种方式使用日志。

新手时期的典型场景

新手时期的典型代码基本都是如下形式的：

import xxx

def func1(xx):
    xxxx
    print(...)
    xxxx

def func2(xx):
    xxxx
    print(...)
    xxxxx
...
if __name__ == '__main__':
    func1(...) ... func2(...)

这样的程序的问题在我这里是以下几个：

1. 修改很繁琐，比如想对不同的print进行区分，你就得往里面写一大堆区分的符号，常见的比如 -----val_1-----；一个小部分debug完了你又得上去删除，有时候你写多了你得到处找，到处去注释

2. 如果涉及递归、循环等会导致大量打印的内容，并且你在终端，比如VScode的终端运行程序，可能都翻不到最顶上，丢失很多展示内容，并且可能只能看一次，你再运行别的程序或者关闭了这个想明天再看，就没了

1. logging 替代 print

为了解决问题1，一般是会使用logging去替代print。有什么好处呢？logging可以用INFO, WARNING, DEBUG, ERROR那些等级去控制，比如你找bug的时候你设置logging等级为比较低的Debug，等到你把你的问题解决完了，你不用到处去找你的logging语句把它们注释掉，你直接把原来的logging等级设置为更高一级的INFO，那些输出就统统失效了

print('...') -> logging.debug('...')
# 当logging的日志级别是debug的时候才会输出，高于debug等级时，不会输出

最基础的使用方式是直接使用logging.xxxx

这样的使用方式下，在主程序中通过 logging.basicConfig() 快速设置输出日志文件的路径、格式、等级等，再在任意位置用 logging.debug()/info()/… 代替 print，那么就会统一使用该配置进行日志输出

import logging

logging.basicConfig(filename="test.log", filemode="w", format="%(asctime)s %(name)s:%(levelname)s:%(message)s", datefmt="%d-%M-%Y %H:%M:%S", level=logging.DEBUG)

# logging.debug(xxx)中的内容为message，而我们设置的format就是message如何和其他的信息结合，比如我们想有记录日志的时间戳等

logging.debug('This is a debug message')
logging.info('This is an info message')
logging.warning('This is a warning message')
logging.error('This is an error message')
logging.critical('This is a critical message')

# 这样会记录得到
23-04-09 12:10:32 root:DEBUG:This is a debug message
23-04-09 12:10:32 root:INFO:This is an info message
23-04-09 12:10:32 root:WARNING:This is a warning message
23-04-09 12:10:32 root:ERROR:This is an error message
23-04-09 12:10:32 root:CRITICAL:This is a critical message

但是用着用着就会发现，还存在一些问题：

2. 前面说的，如果有递归和循环，那不同的函数里写的日志我想要区分开怎么办？-> 取不同的日志器的名字

3. 不同的日志都写在一个文件里，就算前面写着不同的名字，比如上面的例子里日志器都叫root，还是不好看怎么办？比如说，我想要不同函数把不同的日志写在不同的文件里面，我运行一次程序，可以有一个简要版本的日志文件生成出来，还同时有一个细节版本生成出来，让我可以关注一些特定环节的细节

一个一个来

2. 不同的logger

我们需要对logging了解得更深入一些。

上面直接使用logging进行的快速使用，本质上是依靠四大底层组件：

• Logger: 应用程序的小秘，应用程序要记录啥就跟他说，哎，logger，你帮我写一串啥写到哪里
  • 但是logger他也能力有限，他会让更专业的人去干各种专门的事。
• filter：专门对要记录的信息进行细粒度的筛选和过滤，决定哪些要记录，哪些不记录
• formatter：专门把确定要记录的东西结合你想要的信息，变成你想要的格式
• handler：专门负责把日志写到文件系统里面。

当然了，程序员是他们的牛马，大牛程序员负责编写好filter, formatter, handler这些专业人士，封装在logging库里面，并且提供一些改装他们的接口，调包侠程序员们就负责把这些专业人士调教改装，等到专业人士都准备好了，你再从应用程序的视角，仅仅和logger进行简单的沟通就好了

通常，我们可以准备一份配置文件logging.conf，不同的logger，有不同的format，等级等

[loggers]
keys=root,simpleExample

[handlers]
keys=consoleHandler

[formatters]
keys=simpleFormatter

[logger_root]
level=DEBUG
handlers=consoleHandler

[logger_simpleExample]
level=DEBUG
handlers=consoleHandler
qualname=simpleExample
propagate=0

[handler_consoleHandler]
class=StreamHandler
level=DEBUG
formatter=simpleFormatter
args=(sys.stdout,)

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

然后在应用程序中，就可以在不同的函数里按需调取不同的logger。但是注意，logger是遵循单例模式的，也就是说，实际上在一个python解释器中只有一个最最底层的rootLogger，我们创造的那些叫不同的名字、用不同的格式，在我们看来好像他们是不同的，但是实际上他们都会最终利用rootLogger的能力，所以我们不能创造logger实例，比如logger_A = logger()这样，我们只能使用logging.getLogger(name)来取得一个已经存在的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')

基本没有很大的改变，但是确实会让日志中输出的内容更加丰富，有的前面写的root: message balabala；有的前面写的 simpleExample: message balabala，并且可以具备详略得当的格式

3. 不同logger输出到不同的日志文件中

因为是我遇到的一个场景，所以单独讲讲如何把不同日志输出到不同的日志文件中，本质上还是运用2中的知识。我的场景是这样的：我的主程序中有两次多进程相关的内容，一方面我需要记录主程序运行过程中，两次结果汇总是否正确，一方面我需要知道子进程的详细处理过程是否正确。因此就有这样的需求，把主程序的输出到一个文件，把子进程的输出到另外的几个文件里，这样看起来也方便，不会多个进程的输出混在一起。（如果有更好的做法还希望大佬们教教我呀，交流一下）

核心思想就是为一个logger准备它独有的handler，因为handler是负责发送日志message到具体文件的嘛，当然了，它也可以有独有的formatter那些，因为涉及格式

# 某个子进程函数
def worker(...):
    specified_logger = logging.getLogger(log_name) # 取个logger名字
    
    # 创建专有的handler, formatter等
    handler = logging.FileHandler(file_name)
    handler.setFormatter(specified_formatter) 
    
    # 传达给logger
    specified_logger.setLevel(level)
    specified_logger.addHandler(handler)
    
    # 接下来就可以使用该logger输出到不同文件了
    specified_logger.info('...')
    

有时候，我们希望每个函数独立默默地将自己的log输出到对应的文件就行了，不希望它们抢着一起输出到命令行中，此时对每个logger设置logger_name.propagate=False就可以了，它们会抢着输出到命令行，是因为这些自定义的logger其实都是会把message回传到root_logger的，root_logger的handler中有命令行输出的streamHandler，所以就会输出到命令行。如果我们关掉logger的propagate，message就不会被root_logger获取

4. 重复添加指向同一个路径的handler会发生什么？

class CustomLogger:
    def __init__(self, logger_name, logger_file, level=logging.INFO):
        spec_logger = logging.getLogger(logger_name)

        handler = logging.FileHandler(logger_file)
        # handler.setFormatter()

        spec_logger.setLevel(level)
        spec_logger.addHandler(handler)

        spec_logger.propagate = False

        self.logger = spec_logger

    def get_logger(self):
        return self.logger

if __name__ == '__main__':
	for i in range(4):
	    log = CustomLogger('a', './test.log').get_logger()
	    log.info(i)
	    print(i, '---------------')
	    for h in log.handlers:
	        print(h)
	    print('-----------', i)

会发现文件中写道：

0
1
1
2
2
2
3
3
3
3

发现了没有，FileHandler实际上是相互独立的，即便指向同一个路径的FileHandler对象也是彼此独立的。你可以把一个FileHandler理解成一支在固定的位置写字的笔，log message理解为要写的内容，logger是一个写字的手，addHandler就是把笔插到手上，如果我们给同一张纸，N支笔，会发生什么呢？笔迹会重合。但是因为操作系统对于IO的控制，这些“同时书写”之间实际存在一定的延迟，这样一来，就出现了文件里的重复问题。
如何解决呢？

1. 避免重复声明
2. 如果你非要重复声明，插笔的时候请检查是不是已经有这支相同作用的笔了

class CustomLogger:
    def __init__(self, logger_name, logger_file, level=logging.INFO):
        spec_logger = logging.getLogger(logger_name)

        find_handler = False
        for handler in spec_logger.handlers:
            if isinstance(handler, logging.FileHandler) and os.path.samefile(logger_file, handler.baseFilename):
                find_handler = True
                break

        if not find_handler:
            handler = logging.FileHandler(logger_file)
            # handler.setFormatter()
            spec_logger.addHandler(handler)
            spec_logger.setLevel(level)
            spec_logger.propagate = False

        self.logger = spec_logger

    def get_logger(self):
        return self.logger

Conclusion

本篇是python中的一个小但是重要的知识点，也确实困扰过我一阵子，但是后来就会发现很多思想都是统一的。比如写python的人肯定也绕不开matplotlib这个库，深入了解就会发现，它也是一个Artist对象做你的小秘，然后指导专业的Renderer负责专门的显色细节，在FigureCanvas（画布对象）上面画画。明白这一点以后，能够做出很多你需求定制化的更高级的事情，而不是被高级API束手束脚的。

如有错误，还请指正！拜托拜托！

（其实一直蛮害怕半桶水晃荡的时候分享自己的学习心得的，因为能想起学生时代，你和别人对答案，别人在你的答案的基础上，回去琢磨完发现你的答案错了，但是他不告诉你，第二天他对你错的场景，那真是有心理阴影哈哈哈）

But anyway, 做费曼学习法的践行者！必须有人先开始！

Reference

非常推荐阅读的官方文档，说得也很清楚，就是觉得进阶的示例还是少了一些

https://docs.python.org/3/howto/logging.html