理解Python Logging的工作机制
python的logging模块是一个功能强大且灵活的日志记录框架。其核心组件包括：
- Logger（记录器）：应用程序直接与之交互的入口点。它负责接收日志消息，并根据其自身的级别决定是否将消息传递给Handler。
- Handler（处理器）：负责将日志消息发送到指定的目标，如文件、控制台、网络等。每个Handler也有自己的级别，只有当日志消息的级别高于或等于Handler的级别时，Handler才会处理该消息。
- Formatter（格式器）：定义日志消息的输出格式。
日志消息的流动遵循一个严格的流程：
- 当调用logger.info()、logger.debug()等方法时，日志消息被生成。
- 日志消息首先到达Logger。Logger会根据其自身设定的级别对消息进行初步过滤。如果消息级别低于Logger的级别，则该消息会被丢弃，不会传递给任何Handler。
- 如果消息通过了Logger的级别过滤，它将被传递给所有附加到该Logger的Handlers。
- 每个Handler会再次根据其自身的级别对消息进行过滤。只有当消息级别高于或等于Handler的级别时，Handler才会处理该消息。
- 最终，通过Handler过滤的消息会由关联的Formatter进行格式化，然后输出到指定的目标。
INFO级别日志不输出的常见原因
在实践中，许多开发者会遇到这样的情况：即使为文件或控制台设置了logging.INFO级别的Handler，INFO级别的日志仍然无法输出。这通常是因为忽略了Logger本身的级别设置。
核心问题在于：logging.getLogger()在默认情况下，其级别被设置为WARNING。
这意味着，如果一个Logger的级别是WARNING，那么任何低于WARNING级别（如INFO、DEBUG）的日志消息，在到达Handler之前就会被Logger自身过滤掉。即使你为Handler设置了INFO级别，它也永远不会收到那些被Logger提前过滤掉的INFO或DEBUG消息。
立即学习“Python免费学习笔记（深入）”；
考虑以下示例代码，它展示了原始问题中日志不输出的现象：
import logging
import os
def setup_logger(dtc_name, log_dir, is_debug=False, is_interactive=False):
formatter = logging.Formatter("%(asctime)s %(process)s %(levelname)s - %(message)s")
logger = logging.getLogger(dtc_name)
# 关键点：这里没有设置logger的级别，它将默认为WARNING
# 清除现有handlers，防止重复添加
if logger.handlers:
for handler in logger.handlers[:]:
logger.removeHandler(handler)
# INFO级别文件日志
info_log_path = os.path.join(log_dir, f"{dtc_name}.log")
info_log = logging.FileHandler(info_log_path)
info_log.setFormatter(formatter)
info_log.setLevel(logging.INFO) # Handler设置为INFO级别
logger.addHandler(info_log)
# ERROR级别错误日志
error_log_path = os.path.join(log_dir, f"{dtc_name}_error.log")
error_log = logging.FileHandler(error_log_path)
error_log.setFormatter(formatter)
error_log.setLevel(logging.ERROR)
logger.addHandler(error_log)
# 控制台日志
console_log = logging.StreamHandler()
console_log.setFormatter(formatter)
console_log.setLevel(logging.ERROR) # 默认控制台显示ERROR及以上
logger.addHandler(console_log)
# 根据参数调整控制台日志级别
if is_debug:
console_log.setLevel(logging.DEBUG)
elif is_interactive:
console_log.setLevel(logging.INFO)
return logger
def main():
# 假设日志目录为当前目录
log_directory = "."
# 设置Logger，这里is_debug和is_interactive都为False
logger = setup_logger('ExampleLogger', log_directory, is_debug=False, is_interactive=False)
# 打印Logger和Handlers的当前级别，以验证配置
print(f"Logger '{logger.name}' level: {logging.getLevelName(logger.level)}")
for handler in logger.handlers:
print(f"Handler: {handler} | Level: {logging.getLevelName(handler.level)}")
# 记录不同级别的消息
logger.debug('This is a debug message')
logger.info('This is an info message')
logger.warning('This is a warning message')
logger.error('This is an error message')
logger.critical('This is a critical message')
if __name__ == "__main__":
main()运行上述代码，你将观察到类似以下输出：
Logger 'ExampleLogger' level: WARNING # 注意：Logger的级别是WARNING Handler: <FileHandler ./ExampleLogger.log (INFO)> | Level: INFO Handler: <FileHandler ./ExampleLogger_error.log (ERROR)> | Level: ERROR Handler: <StreamHandler <stderr> (ERROR)> | Level: ERROR 2023-11-27 16:42:16,304 244 WARNING - This is a warning message 2023-11-27 16:42:16,305 244 ERROR - This is an error message 2023-11-27 16:42:16,305 244 CRITICAL - This is a critical message
从输出中可以清晰地看到，Logger本身的级别是WARNING。这意味着DEBUG和INFO级别的消息在到达任何Handler之前就被Logger过滤掉了，因此无论是文件还是控制台，都无法接收到并打印这些低级别日志。
解决方案：显式设置Logger的级别
要解决这个问题，最直接的方法是在获取Logger实例后，显式地设置其日志级别。将其级别设置为INFO或DEBUG，以确保所有预期级别的日志消息都能通过Logger的初步过滤。
以下是修正后的setup_logger函数：
import logging
import os
def setup_logger(dtc_name, log_dir, is_debug=False, is_interactive=False):
formatter = logging.Formatter("%(asctime)s %(process)s %(levelname)s - %(message)s")
logger = logging.getLogger(dtc_name)
# 核心修正：显式设置Logger的级别
if is_debug:
logger.setLevel(logging.DEBUG) # 调试模式下Logger级别设置为DEBUG
elif is_interactive:
logger.setLevel(logging.INFO) # 交互模式下Logger级别设置为INFO
else:
logger.setLevel(logging.INFO) # 默认情况下Logger级别也设置为INFO，以捕获INFO日志
# 清除现有handlers，防止重复添加
if logger.handlers:
for handler in logger.handlers[:]:
logger.removeHandler(handler)
# INFO级别文件日志
info_log_path = os.path.join(log_dir, f"{dtc_name}.log")
info_log = logging.FileHandler(info_log_path)
info_log.setFormatter(formatter)
info_log.setLevel(logging.INFO) # Handler设置为INFO级别
logger.addHandler(info_log)
# ERROR级别错误日志
error_log_path = os.path.join(log_dir, f"{dtc_name}_error.log")
error_log = logging.FileHandler(error_log_path)
error_log.setFormatter(formatter)
error_log.setLevel(logging.ERROR)
logger.addHandler(error_log)
# 控制台日志
console_log = logging.StreamHandler()
console_log.setFormatter(formatter)
# 控制台Handler的默认级别可以根据is_debug/is_interactive在后面设置
logger.addHandler(console_log)
# 根据is_debug和is_interactive参数调整控制台日志级别
if is_debug:
console_log.setLevel(logging.DEBUG)
elif is_interactive:
console_log.setLevel(logging.INFO)
else:
console_log.setLevel(logging.ERROR) # 默认控制台显示ERROR及以上
return logger
def main():
log_directory = "."
# 示例1: 默认模式 (Logger和info_log Handler都是INFO，console_log Handler是ERROR)
print("\n--- 示例1: 默认模式 ---")
logger_default = setup_logger('ExampleLoggerDefault', log_directory, is_debug=False, is_interactive=False)
print(f"Logger '{logger_default.name}' level: {logging.getLevelName(logger_default.level)}")
for handler in logger_default.handlers:
print(f"Handler: {handler} | Level: {logging.getLevelName(handler.level)}")
logger_default.debug('Default: This is a debug message')
logger_default.info('Default: This is an info message')
logger_default.warning('Default: This is a warning message')
logger_default.error('Default: This is an error message')
logger_default.critical('Default: This is a critical message')
# 示例2: 交互模式 (Logger和info_log Handler都是INFO，console_log Handler也是INFO)
print("\n--- 示例2: 交互模式 ---")
logger_interactive = setup_logger('ExampleLoggerInteractive', log_directory, is_debug=False, is_interactive=True)
print(f"Logger '{logger_interactive.name}' level: {logging.getLevelName(logger_interactive.level)}")
for handler in logger_interactive.handlers:
print(f"Handler: {handler} | Level: {logging.getLevelName(handler.level)}")
logger_interactive.debug('Interactive: This is a debug message')
logger_interactive.info('Interactive: This is an info message')
logger_interactive.warning('Interactive: This is a warning message')
logger_interactive.error('Interactive: This is an error message')
logger_interactive.critical('Interactive: This is a critical message')
# 示例3: 调试模式 (Logger和所有Handler都是DEBUG)
print("\n--- 示例3: 调试模式 ---")
logger_debug = setup_logger('ExampleLoggerDebug', log_directory, is_debug=True, is_interactive=False)
print(f"Logger '{logger_debug.name}' level: {logging.getLevelName(logger_debug.level)}")
for handler in logger_debug.handlers:
print(f"Handler: {handler} | Level: {logging.getLevelName(handler.level)}")
logger_debug.debug('Debug: This is a debug message')
logger_debug.info('Debug: This is an info message')
logger_debug.warning('Debug: This is a warning message')
logger_debug.error('Debug: This is an error message')
logger_debug.critical('Debug: This is a critical message')
if __name__ == "__main__":
main()运行修正后的代码，你会看到INFO级别的日志以及在调试模式下的DEBUG级别日志都能够正常输出。例如，在示例1（默认模式）下，控制台仍只会显示WARNING及以上日志，但文件ExampleLoggerDefault.log中将包含INFO、WARNING、ERROR、CRITICAL级别的日志。在示例2（交互模式）下，控制台也会显示INFO及以上日志。
注意事项与最佳实践
- Logger级别是第一道关卡：始终记住，日志消息首先通过Logger的级别过滤，然后才到达Handler。如果Logger的级别设置得太高，即使Handler的级别很低，也无法捕获到低级别的日志。
-
合理设置Logger和Handler级别：
- Logger的级别：通常设置为你希望应用程序能够记录的最低级别（例如，在开发环境中设置为DEBUG，在生产环境中设置为INFO或WARNING）。
- Handler的级别：可以根据输出目标的不同而设置。例如，文件Handler可以设置为INFO以记录所有重要信息，而控制台Handler可以设置为WARNING或ERROR，只显示关键错误。
- Root Logger：如果没有通过logging.getLogger('your_logger_name')获取特定的Logger，而是直接使用logging.debug()、logging.info()等函数，那么你是在使用根Logger（Root Logger）。根Logger的默认级别也是WARNING。若要修改，需使用logging.basicConfig()或logging.getLogger().setLevel()。
- 避免重复添加Handler：在重复调用setup_logger函数时，务必清除Logger上已有的Handler，如示例代码中所示的if logger.handlers: for handler in logger.handlers[:]: logger.removeHandler(handler)。否则，每次调用都会添加新的Handler，导致日志重复输出。
- 模块化日志配置：对于大型项目，建议将日志配置逻辑封装在单独的模块或函数中，以便于管理和复用。
总结
Python logging模块的强大之处在于其灵活性，但这也要求开发者深入理解其内部机制。当遇到INFO级别日志不输出的问题时，最常见且最根本的原因是Logger本身的级别设置过高。通过显式地使用logger.setLevel()方法，将Logger的级别设置为与预期日志级别相符或更低的级别，即可确保日志消息能够正确地通过Logger的初步过滤，并最终被相应的Handler处理和输出。掌握这一核心概念，将有助于你更有效地利用logging模块进行应用程序的调试和监控。
