新创建的 logger 为何无法正确 “发声”，不怀好意的日志究竟从何而来，精心配置的 logger 竟然然口口吐吐叠叠词词，到底是配置者的失误还是来自三方库的暗箱操作，欢迎走进 logging 详解的第一期：《是谁偷偷动了我的 logger》。
GOODGOOD，通过 mmcv 配置的 logger 日志格式整齐，还能将日志导出到文件，能够很好的备份实验数据，舒服～
诶，最近 torch 也更新了，赶快跟上的时代的步伐，给自己的训练任务升个级！
调试完成，实验启动！
代码语言：javascript复制2022-01-28 15:01:45,436 - mmdet - INFO - Epoch [1][0/7330] lr: 1.000e-02, eta: 8:28:55, time: 0.248, data_time: 0.008, memory: 3510, loss_cls: 0.9523, loss_bbox: 0.6255, loss: 1.5778
Epoch [1][0/7330] lr: 1.000e-02, eta: 8:28:55, time: 0.248, data_time: 0.008, memory: 3510, loss_cls: 0.9523, loss_bbox: 0.6255, loss: 1.5778
Epoch [1][0/7330] lr: 1.000e-02, eta: 8:28:55, time: 0.248, data_time: 0.008, memory: 3510, loss_cls: 0.9523, loss_bbox: 0.6255, loss: 1.5778
Epoch [1][0/7330] lr: 1.000e-02, eta: 8:28:55, time: 0.248, data_time: 0.008, memory: 3510, loss_cls: 0.9523, loss_bbox: 0.6255, loss: 1.5778
...纳尼，日志怎么影分身了，几张卡就有几次重复的日志，不应该啊，这难道就是卡多的烦恼？我 mmcv 版本也没更新，只是更新了 torch，按理说 logger 都是一样的配方，为啥日志乱了呢？
为了解决多重日志的 bug，我追根溯源的对 python 的 logging 模块进行了地毯式的 debug。在我第 10086 次调试过程中，出现了诡异的现象：
代码语言：javascript复制>>> # import “三方”库
>>> logger = logging.getLogger("misery debug")
>>> logger.setLevel(logging.INFO)
>>> logger.info("问题究竟在哪")
misery debug 现在的年轻人难道希望问题很好定位，bug 很好修，程序一跑就 ok？不会吧？我的日志 "问题究竟在哪" 为什么没有显示？这句 "misery debug 现在的年轻人难道希望问题很好定位，bug 很好修，程序一跑就 ok？不会吧？" 又是从哪来的？到底是谁对我的 logger 动了手脚？
问题一：我的 logger 去哪了✦
上例中，我明明想输出 “问题究竟在哪”，但是为什么这条日志没有在终端出现呢？事实上，使用 logging .getLogger 接口获取的 logger，只是一个胚胎，本身不具备任何输出日志的能力。logger 是通过自身携带的 handler 来输出日志的，例如 StreamHandler（向终端输出日志）和 FileHandler（向文件输出日志）。所以我们需要为创建的 logger 配置 handler，从而能够实现输出日志的功能。
代码语言：javascript复制>>> logger = logging.getLogger("misery debug")
>>> logger.setLevel(logging.INFO)
>>> logger.handlers.addHandler(logging.StreamHandler())
>>> logger.info("问题究竟在哪")
问题究竟在哪
misery debug 现在的年轻人难道希望问题很好定位，bug 很好修，程序一跑就 ok，不会吧？在为 logger 配置上 StreamHandler 后，日志就能正常输出了。
问题二：是谁在默默低语✦
misery debug 现在的年轻人难道希望问题很好定位，bug 很好修，程序一跑就 ok，不会吧？
这句嘲讽的打印和 mmcv 日志多重打印其实是一回事，而 logging 库的继承关系则是这一系列问题的症结所在。
众所可能不周知， logging 库为了简化配置 logger 的流程，允许我们通过派生“子实例”来获取日志格式和父实例一样的 logger。为了便于介绍日志格式的继承关系，下例中我们直接使用 mmcv.get_logger 函数来获取 logger（get_logger 接口能够获取有统一日志格式的 logger）。
代码语言：javascript复制>>> parent_logger = mmcv.get_logger('parent')
>>> child_logger = parent_logger.getChild('child')
>>> child_logger.info("I'm child")
2022-03-01 21:58:18,438 - parent.child - INFO - I'm childlogging.Logger.getChild() 方法能够非常简单的获取具有相同日志格式的子实例，但是这也是多重日志的根源。
鲁迅曾经说过，人类拥有共同的祖先，logger 也不例外，那就是 logging.root 。所有通过 logging.getLogger 方法创建的实例，都拥有共同的祖先：logging.root。
代码语言：javascript复制>>> logger = logging.getLogger('roommate')
>>> logger = logger.getChild('roommate')
>>> logger = logger.getChild('roommate')
>>> logger = logger.getChild('roommate')
>>> while logger.parent:
>>> print(logger.parent.name)
>>> logger = logger.parent
roommate.roommate.roommate
roommate.roommate
roommate
root这样就会引入一个问题，如果三方库配置了 logging.root ，按照继承逻辑是否会影响到我们的日志呢，答案是会的。我仔细检查了我导入的模块（自导自演），终于找到了 devil_whisper.py。
代码语言：javascript复制import logging
handler = logging.StreamHandler()
format = logging.Formatter("%(name)s 现在的年轻人难道希望问题很好定位，bug 很好修，程序一跑就 ok，不会吧？")
handler.setFormatter(format)
handler.setLevel(logging.INFO)
logging.root.addHandler(handler)由于 logging.getLogger("misery debug") 获取的 logger 继承自 logging.root，因此就会输出 misery debug 现在的年轻人难道希望问题很好定位，bug 很好修，程序一跑就 ok，不会吧？
mmcv 出现多重日志的原因也是如此。尽管 mmcv 的 mmcv.get_logger 会将 logging.root 的 handler 的日志等级设置成 ERROR，从而过滤所有 ERROR 等级以下的日志，但是如果三方库在 mmcv.get_logger 之后再配置 logging.root，就会出现多重日志的现象。
代码语言：javascript复制# https://github.com/open-mmlab/mmcv/blob/master/mmcv/utils/logging.py
>>> def get_logger(name, log_file=None, log_level=logging.INFO, file_mode='w'):
>>> ...
>>> for handler in logger.root.handlers:
>>> if type(handler) is logging.StreamHandler:
>>> handler.setLevel(logging.ERROR)
>>> ...
>>> return logger
>>> logging.root.addHandler(logging.StreamHandler())
>>> logger = get_logger('mmcv') # 将 Handler 的日志等级设置为 ERROR.
>>> logger.info('不会触发多重日志！')
2022-03-01 22:16:42,682 - mmcv - INFO - 不会触发多重日志！
>>> logging.root.addHandler(logging.StreamHandler()) # root 新增了 handler.
>>> logger.info('触发多重日志！')
2022-03-01 22:16:42,682 - mmcv - INFO - 触发多重日志！
触发多重日志！既然继承是多重日志的万恶之源，我们就需要理解 logging.Logger 的继承逻辑，这边以流程图的形式展示 handler 的继承规则。
Handler 的继承规则
不难发现，logging 模块通过 propagate 属性实现了 handler 的 “继承”。当 propagate 为 True 时，子实例会向上搜索并调用父实例的 Handler 从而触发多重打印。我们只需要另 propagate 为 False，能走出万恶的继承循环了。
代码语言：javascript复制>>> logging.root.addHandler(logging.StreamHandler())
>>> logger = mmcv.get_logger('mmcv')
>>> logger.propagate = False
>>> logger.info('不会触发多重日志！')
2022-03-01 22:31:03,429 - mmcv - INFO - 不会触发多重日志！
>>> logging.root.addHandler(logging.StreamHandler())
>>> logger.info('触发多重日志！')
2022-03-01 22:31:03,429 - mmcv - INFO - 触发多重日志！可以看到两句话都只被打印了一遍，问题成功解决。
虽然找到了多重日志的根源，但这只是 logging 模块的冰山一角。如何配置会 “察言观色” 的 logger，能够按照日志等级输出不同格式的日志，如何缕清 logger 父子实例复杂的继承关系？尽情期待第二期：《三句话，让 logger 对我言听计从》～
