Python自定义模块Logging问题求助：默认禁用与日志重复异常

问题概述 #

我想给自己的模块实现自定义Logging功能，但遇到两个问题：

• 调用setLevel(0)无法禁用日志
• 使用basicConfig(level=0)会导致日志重复输出，还带默认格式

我的目标：默认禁用模块日志，且不影响用户；用户导入logging和我的模块后，只需执行logging.getLogger('rapidTk').setLevel(99)就能启用指定级别的日志。

相关代码 #

rapidTk/__init__.py

from .rTkLogging import rTkLogger

import logging
logging.setLoggerClass(rTkLogger)
rtklog = logging.getLogger('rapidTk')
rtklog.setLevel(0)

rapidTk/rTkLogger.py

import logging
RTKLOG = 1
class rTkLogger(logging.Logger):
    logging.addLevelName(RTKLOG, 'rTk_Log')
    def __init__(self, name):
        super(rTkLogger, self).__init__(name)
        handler = logging.StreamHandler()
        fmat = logging.Formatter('%(asctime)s %(levelname)s %(filename)s(%(lineno)d) - %(message)s')
        handler.setFormatter(fmat)
        hndlr = self.addHandler(handler)
        self.setLevel(0)
    def rtklog(self, msg, *args, **kwargs):
        print(self.getEffectiveLevel(), 'is the effective level')
        if self.getEffectiveLevel() >= RTKLOG and self.isEnabledFor(self.getEffectiveLevel()):
            super()._log(RTKLOG, msg, args, **kwargs)

rapidTk/rTkUtils.py

from functools import wraps
from time import perf_counter
import logging

def time_it(func):
    def wrapper(*args, **kwargs):
        start = perf_counter()
        fn = func
        rs = fn(*args, **kwargs)
        t = perf_counter()-start
        logging.getLogger('rapidTk').rtkdebug(f'{fn.__name__} finished in {t}')
        return rs
    return wrapper

projects/mypythonscript.py

import logging
#logging.basicConfig(level=10) ## 启用级别后日志重复
import time
from rapidTk import *
from rapidTk.rTkUtils import time_it
#rtklog = logging.getLogger('rapidTk')
#rtklog.setLevel(0) ## 无效果

@time_it
def runner():
    print("hello")
    time.sleep(1)
    print("World")
    
if __name__ == "__main__":
    runner()
    print("done")

不同场景的输出 #

执行basicConfig(level=10)时的输出

>>> 10 is the effective level
>>> 2022-12-01 17:14:57,161 rTk_Debug rTkUtils.py(17) - tester finished in 1.0115269999987504
>>> rTk_Debug:rapidTk:tester finished in 1.0115269999987504

执行setLevel(0)时的输出

>>> 30 is the effective level
>>>2022-12-01 17:16:52,528 rTk_Debug rTkUtils.py(17) - tester finished in 0.9971981999988202

问题原因与修复方案 #

1. setLevel(0)无法禁用日志的原因 #

• 自定义rtklog方法的判断逻辑搞反了：应该判断日志级别RTKLOG是否大于等于当前生效级别，而不是反过来；
• rTkLogger的__init__里硬编码了self.setLevel(0)，直接覆盖了你在__init__.py里设置的级别。

2. 日志重复输出的原因 #

自定义Logger的__init__里直接添加了StreamHandler，用户调用basicConfig时会自动生成另一个默认的StreamHandler，两个Handler同时输出导致重复。

修复后的代码 #

修改rapidTk/rTkLogger.py

import logging
RTKLOG = 1
logging.addLevelName(RTKLOG, 'rTk_Log')

class rTkLogger(logging.Logger):
    def __init__(self, name):
        super().__init__(name)
        # 默认设为比最高级别CRITICAL（50）还高的数值，彻底禁用所有日志
        self.setLevel(logging.CRITICAL + 1)
        # 不主动添加Handler，让用户自行配置格式和输出渠道

    def rtklog(self, msg, *args, **kwargs):
        # 正确判断：当前Logger级别是否允许输出RTKLOG级别的日志
        if self.isEnabledFor(RTKLOG):
            super()._log(RTKLOG, msg, args, **kwargs)

    # 补充原代码中调用但未定义的rtkdebug方法
    def rtkdebug(self, msg, *args, **kwargs):
        DEBUG_LEVEL = 10
        logging.addLevelName(DEBUG_LEVEL, 'rTk_Debug')
        if self.isEnabledFor(DEBUG_LEVEL):
            super()._log(DEBUG_LEVEL, msg, args, **kwargs)

修改rapidTk/__init__.py

from .rTkLogging import rTkLogger
import logging

logging.setLoggerClass(rTkLogger)
rtklog = logging.getLogger('rapidTk')
# 不再手动设置级别，依赖Logger初始化时的默认禁用配置

验证效果 #

• 默认状态下，模块日志完全禁用，不会输出任何内容；
• 用户启用日志时，只需执行以下代码：

import logging
from rapidTk import *

rtk_logger = logging.getLogger('rapidTk')
rtk_logger.setLevel(1)  # 启用RTKLOG级别，或者设为99（对应自定义级别）
# 如需自定义格式，用户可自行添加Handler
handler = logging.StreamHandler()
formatter = logging.Formatter('%(asctime)s %(levelname)s %(filename)s(%(lineno)d) - %(message)s')
handler.setFormatter(formatter)
rtk_logger.addHandler(handler)

这样既不会干扰用户的Logging配置，也能实现自定义日志的按需启用。

内容的提问来源于stack exchange，提问作者Scott Paterson