咳咳，各位观众老爷们，大家好！欢迎来到今天的“Python 高级技术之 TDD 日志捕获奇妙之旅”讲座。我是你们的老朋友，代码界的段子手，今天就带大家一起扒一扒 logging 模块在 TDD (测试驱动开发) 中如何发挥神力。
引子：为什么 TDD 需要日志？
咱们先唠唠嗑，为啥 TDD 这么喜欢日志？你想啊，TDD 嘛，先写测试，再写代码，红绿灯不断切换。但有时候，测试失败了，错误信息不够给力啊！就像你跟女神表白失败，她只甩给你一句“你是个好人”，然后你就傻眼了，好人咋了？哪里好？哪里不好？
日志就好比女神给你的详细反馈：
- 详细错误信息: 告诉你哪里崩了，崩到什么程度。
- 上下文信息: 告诉你崩的时候发生了什么，有哪些关键变量的值。
- 帮助调试: 让你不再盲猜，能更精准地定位问题。
- 长期监控: 代码上线后，日志还能帮你监控系统健康状况。
所以，日志是 TDD 的好伙伴，有了它，debug 就像开了上帝视角，效率嗖嗖地！
第一站：logging 模块基础回顾
logging 模块是 Python 自带的日志神器，功能强大，配置灵活。先来复习一下基本概念：
- Logger: 日志器，是
logging系统的入口，负责接收日志信息。 - Handler: 处理器，决定日志信息输出到哪里，比如控制台、文件、网络。
- Formatter: 格式器，定义日志信息的输出格式，比如时间、级别、内容。
- Level: 日志级别，表示日志的严重程度，从低到高依次是
DEBUG,INFO,WARNING,ERROR,CRITICAL。
简单示例：
import logging
# 创建一个 logger
logger = logging.getLogger('my_app')
logger.setLevel(logging.DEBUG) # 设置日志级别
# 创建一个 handler，输出到控制台
console_handler = logging.StreamHandler()
console_handler.setLevel(logging.DEBUG)
# 创建一个 formatter，定义输出格式
formatter = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s')
console_handler.setFormatter(formatter)
# 将 handler 添加到 logger
logger.addHandler(console_handler)
# 记录日志
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')这段代码创建了一个名为 my_app 的 logger，并将日志输出到控制台，日志级别设置为 DEBUG。你会看到类似这样的输出：
2023-10-27 10:00:00,000 - my_app - DEBUG - This is a debug message
2023-10-27 10:00:00,000 - my_app - INFO - This is an info message
2023-10-27 10:00:00,000 - my_app - WARNING - This is a warning message
2023-10-27 10:00:00,000 - my_app - ERROR - This is an error message
2023-10-27 10:00:00,000 - my_app - CRITICAL - This is a critical message第二站：TDD 中的日志捕获策略
现在，咱们来聊聊如何在 TDD 中优雅地捕获日志。核心思想是：
- 测试代码执行时，将日志信息捕获到内存中。
- 测试完成后，检查捕获到的日志信息是否符合预期。
这就像在代码里埋伏了个间谍，偷偷记录敌人的动向，然后汇报给总部。
2.1 使用 io.StringIO 模拟日志输出
io.StringIO 可以在内存中创建一个类似文件的对象，我们可以将日志输出到这个对象，然后在测试中读取它的内容。
import logging
import io
import unittest
class MyClass:
def divide(self, a, b):
logger = logging.getLogger(__name__)
try:
result = a / b
logger.info(f"Dividing {a} by {b} resulted in {result}")
return result
except ZeroDivisionError:
logger.error(f"Attempted to divide {a} by zero")
return None
class TestMyClass(unittest.TestCase):
def setUp(self):
# 创建一个 logger
self.logger = logging.getLogger(MyClass.__name__)
self.logger.setLevel(logging.DEBUG)
# 创建一个 StringIO 对象，用于捕获日志
self.log_capture = io.StringIO()
# 创建一个 StreamHandler，将日志输出到 StringIO 对象
self.handler = logging.StreamHandler(self.log_capture)
formatter = logging.Formatter('%(levelname)s - %(message)s')
self.handler.setFormatter(formatter)
# 将 handler 添加到 logger
self.logger.addHandler(self.handler)
self.my_class = MyClass()
def tearDown(self):
# 移除 handler，防止影响其他测试
self.logger.removeHandler(self.handler)
def test_divide_success(self):
result = self.my_class.divide(10, 2)
self.assertEqual(result, 5.0)
self.assertIn("INFO - Dividing 10 by 2 resulted in 5.0", self.log_capture.getvalue())
def test_divide_by_zero(self):
result = self.my_class.divide(10, 0)
self.assertIsNone(result)
self.assertIn("ERROR - Attempted to divide 10 by zero", self.log_capture.getvalue())
if __name__ == '__main__':
unittest.main()这个例子中，setUp 方法做了这些事：
- 创建了一个
StringIO对象self.log_capture。 - 创建了一个
StreamHandler，并将输出目标设置为self.log_capture。 - 将
handler添加到logger。
在测试方法中，我们调用 self.log_capture.getvalue() 获取所有捕获到的日志信息，然后使用 self.assertIn 断言日志信息是否包含预期内容。
tearDown 方法负责移除 handler，防止影响其他测试用例。
2.2 使用 logging.captureWarnings 捕获警告信息
有时候，代码会产生警告信息，我们也需要捕获这些信息。logging.captureWarnings(True) 可以将 warnings 模块发出的警告信息重定向到 logging 系统。
import logging
import warnings
import unittest
import io
class MyClass:
def deprecated_function(self):
warnings.warn("This function is deprecated", DeprecationWarning)
return "Hello"
class TestMyClass(unittest.TestCase):
def setUp(self):
self.logger = logging.getLogger(MyClass.__name__)
self.logger.setLevel(logging.DEBUG)
self.log_capture = io.StringIO()
self.handler = logging.StreamHandler(self.log_capture)
formatter = logging.Formatter('%(levelname)s - %(message)s')
self.handler.setFormatter(formatter)
self.logger.addHandler(self.handler)
self.my_class = MyClass()
logging.captureWarnings(True) # 关键：捕获警告信息
def tearDown(self):
self.logger.removeHandler(self.handler)
logging.captureWarnings(False)
def test_deprecated_function(self):
result = self.my_class.deprecated_function()
self.assertEqual(result, "Hello")
self.assertIn("WARNING - This function is deprecated", self.log_capture.getvalue())
if __name__ == '__main__':
unittest.main()2.3 使用 logging.NullHandler 避免 "No handlers could be found" 警告
如果你在代码中使用了 logging，但没有配置任何 handler，Python 会发出 "No handlers could be found for logger…" 警告。这就像你买了台跑车，却没加汽油，只能干瞪眼。
logging.NullHandler 可以解决这个问题。它是一个什么都不做的 handler，可以作为默认的 handler 添加到 logger。
import logging
# 创建一个 logger
logger = logging.getLogger('my_lib')
# 添加一个 NullHandler
logger.addHandler(logging.NullHandler())
# 记录日志
logger.debug('This is a debug message') # 不会输出任何内容在你的库代码中，添加 NullHandler 可以避免用户忘记配置 handler 时出现警告。
第三站：更高级的日志捕获技巧
上面的方法已经很不错了，但还有一些更高级的技巧，可以让你的日志捕获更上一层楼。
3.1 使用 unittest.mock 模拟 logging 对象
unittest.mock 模块可以模拟 Python 对象，包括 logging 对象。这在某些情况下非常有用，比如：
- 测试日志级别过滤: 你可以模拟
logger.isEnabledFor方法，强制 logger 记录特定级别的日志。 - 测试日志参数: 你可以模拟
logger.log方法，检查日志信息是否包含正确的参数。
import unittest
from unittest.mock import patch
import logging
class MyClass:
def process_data(self, data):
logger = logging.getLogger(__name__)
if not isinstance(data, list):
logger.warning("Data is not a list")
return None
logger.info(f"Processing data: {data}")
return True
class TestMyClass(unittest.TestCase):
@patch('logging.Logger.log') # 模拟 Logger.log 方法
def test_process_data_invalid(self, mock_log):
my_class = MyClass()
result = my_class.process_data("not a list")
self.assertIsNone(result)
mock_log.assert_called_with(logging.WARNING, "Data is not a list") # 检查 log 方法是否被调用，以及参数是否正确
@patch('logging.Logger.log')
def test_process_data_valid(self, mock_log):
my_class = MyClass()
data = [1, 2, 3]
result = my_class.process_data(data)
self.assertTrue(result)
mock_log.assert_called_with(logging.INFO, f"Processing data: {data}")
if __name__ == '__main__':
unittest.main()在这个例子中，@patch('logging.Logger.log') 装饰器将 logging.Logger.log 方法替换成了一个 mock 对象 mock_log。
mock_log.assert_called_with 方法可以检查 mock_log 是否被调用，以及调用时传入的参数是否符合预期。
3.2 使用 logging.config.dictConfig 加载日志配置
logging.config.dictConfig 可以从一个字典中加载日志配置。这使得日志配置更加灵活，可以方便地在不同环境中使用不同的配置。
import logging.config
import unittest
import io
class MyClass:
def do_something(self):
logger = logging.getLogger(__name__)
logger.info("Doing something important")
class TestMyClass(unittest.TestCase):
def setUp(self):
self.log_capture = io.StringIO()
logging_config = {
'version': 1,
'disable_existing_loggers': False,
'formatters': {
'simple': {
'format': '%(levelname)s - %(message)s'
}
},
'handlers': {
'console': {
'class': 'logging.StreamHandler',
'level': 'DEBUG',
'formatter': 'simple',
'stream': self.log_capture
}
},
'loggers': {
MyClass.__name__: {
'handlers': ['console'],
'level': 'INFO',
'propagate': False
}
}
}
logging.config.dictConfig(logging_config)
self.logger = logging.getLogger(MyClass.__name__)
self.my_class = MyClass()
def test_do_something(self):
self.my_class.do_something()
self.assertIn("INFO - Doing something important", self.log_capture.getvalue())
if __name__ == '__main__':
unittest.main()在这个例子中，我们定义了一个 logging_config 字典，包含了日志配置信息。logging.config.dictConfig(logging_config) 将这个配置应用到 logging 系统。
第四站：最佳实践与注意事项
- 为每个模块创建一个 logger: 使用
logging.getLogger(__name__)为每个模块创建一个 logger，方便管理和配置。 - 设置合适的日志级别: 根据日志的严重程度选择合适的日志级别，避免记录过多无用信息。
- 使用有意义的日志信息: 日志信息应该包含足够的信息，帮助你定位问题。
- 避免在生产环境中使用
DEBUG级别:DEBUG级别的日志信息通常包含大量细节，可能会影响性能。 - 定期清理日志文件: 日志文件会占用磁盘空间，需要定期清理。
- 使用结构化日志: 结构化日志 (例如 JSON 格式) 更易于分析和处理。可以使用第三方库 (例如
structlog) 来实现结构化日志。 - 考虑使用日志聚合工具: 如果你的应用部署在多个服务器上，可以考虑使用日志聚合工具 (例如 ELK Stack) 来集中管理和分析日志。
总结：
今天我们一起学习了如何在 TDD 中利用 logging 模块进行日志捕获。掌握这些技巧，可以让你在 TDD 过程中更加高效地定位问题，编写出更健壮的代码。记住，日志是你的好朋友，善用它，你会发现编程之路更加顺畅。
表格总结:
| 技术点 | 描述 | 示例代码