为什么我们需要更好的日志记录

记得刚开始写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:日志文件过大

最初我们让日志无限增长,很快就出现了磁盘空间告警。解决方案是使用RotatingFileHandlerTimedRotatingFileHandler

问题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()乱用到现在的结构化日志,这个过程让我深刻体会到:好的日志就像好的文档,是给未来自己(和同事)的一份礼物。