为什么我们需要更好的日志记录
记得刚开始写Python项目时,我总是习惯性地用print()来调试和跟踪程序运行。在小型脚本中这没什么问题,但随着项目规模扩大,特别是在团队协作中,这种随意的打印语句很快就变成了维护的噩梦。日志混乱、难以定位问题、生产环境调试困难——这些都是我亲身经历过的痛点。
标准日志模块的基础用法
Python内置的logging模块为我们提供了强大的日志记录能力。下面是一个基础配置示例:
import logging
# 基础配置
logging.basicConfig(
level=logging.INFO,
format='%(asctime)s - %(name)s - %(levelname)s - %(message)s',
handlers=[
logging.FileHandler('app.log'),
logging.StreamHandler()
]
)
logger = logging.getLogger(__name__)
# 使用示例
def process_data(data):
logger.info(f"开始处理数据,长度: {len(data)}")
try:
result = complex_operation(data)
logger.info("数据处理完成")
return result
except Exception as e:
logger.error(f"处理数据时出错: {e}", exc_info=True)
raise
实际工作中的最佳实践
经过多个项目的迭代,我总结出以下实用的日志记录原则:
1. 合理的日志级别划分
- DEBUG: 详细的调试信息,开发时使用
- INFO: 正常的程序运行信息
- WARNING: 潜在的问题提示
- ERROR: 错误信息,但不影响程序继续运行
- CRITICAL: 严重错误,可能导致程序终止
2. 结构化日志配置
我通常会在项目中创建一个专门的日志配置模块:
# log_config.py
import logging
import logging.config
LOGGING_CONFIG = {
'version': 1,
'disable_existing_loggers': False,
'formatters': {
'standard': {
'format': '%(asctime)s [%(levelname)s] %(name)s: %(message)s'
},
'detailed': {
'format': '%(asctime)s [%(levelname)s] %(name)s %(filename)s:%(lineno)d: %(message)s'
},
},
'handlers': {
'console': {
'class': 'logging.StreamHandler',
'formatter': 'standard',
'level': 'INFO'
},
'file': {
'class': 'logging.handlers.RotatingFileHandler',
'formatter': 'detailed',
'filename': 'app.log',
'maxBytes': 10485760, # 10MB
'backupCount': 5,
'level': 'DEBUG'
},
},
'loggers': {
'': { # root logger
'handlers': ['console', 'file'],
'level': 'DEBUG',
},
'my_project': {
'handlers': ['console', 'file'],
'level': 'INFO',
'propagate': False
}
}
}
def setup_logging():
logging.config.dictConfig(LOGGING_CONFIG)
3. 在业务代码中的具体应用
在具体的业务逻辑中,我遵循这些指导原则:
import logging
from log_config import setup_logging
setup_logging()
logger = logging.getLogger(__name__)
class DataProcessor:
def __init__(self):
self.logger = logging.getLogger(f"{__name__}.DataProcessor")
def process_batch(self, items):
self.logger.info(f"开始处理批次,项目数量: {len(items)}")
successful = 0
failed = 0
for i, item in enumerate(items):
try:
self.logger.debug(f"处理第 {i+1} 个项目: {item['id']}")
self._process_single(item)
successful += 1
except ValueError as e:
self.logger.warning(f"项目 {item['id']} 验证失败: {e}")
failed += 1
except Exception as e:
self.logger.error(f"处理项目 {item['id']} 时发生意外错误",
exc_info=True, extra={'item_id': item['id']})
failed += 1
self.logger.info(f"批次处理完成 - 成功: {successful}, 失败: {failed}")
return successful, failed
遇到的坑与解决方案
问题1:日志文件过大
最初我们让日志无限增长,很快就出现了磁盘空间告警。解决方案是使用RotatingFileHandler或TimedRotatingFileHandler。
问题2:性能影响
在IO密集的场景中,同步日志写入可能成为瓶颈。我们后来引入了异步日志处理:
from concurrent.futures import ThreadPoolExecutor
import logging
class AsyncLogHandler(logging.Handler):
def __init__(self, base_handler):
super().__init__()
self.base_handler = base_handler
self.executor = ThreadPoolExecutor(max_workers=1)
def emit(self, record):
self.executor.submit(self._async_emit, record)
def _async_emit(self, record):
self.base_handler.emit(record)
问题3:敏感信息泄露
曾经发生过日志中记录了用户敏感信息的安全事件。现在我们使用过滤器:
class SensitiveInfoFilter(logging.Filter):
def filter(self, record):
if hasattr(record, 'msg') and isinstance(record.msg, str):
# 脱敏处理
record.msg = self._mask_sensitive_data(record.msg)
return True
def _mask_sensitive_data(self, message):
# 实现具体的脱敏逻辑
import re
message = re.sub(r'\b\d{4}-\d{4}-\d{4}-\d{4}\b', '****-****-****-****', message)
return message
总结
良好的日志记录不仅仅是技术选择,更是一种开发习惯。它让我在深夜排查线上问题时能够快速定位,在代码审查时能够理解同事的逻辑,在新成员加入时能够通过日志了解系统运行状态。从最初的print()乱用到现在的结构化日志,这个过程让我深刻体会到:好的日志就像好的文档,是给未来自己(和同事)的一份礼物。
暂无评论