Django中使用logging导致日志文件损坏的原因排查求助

问题概述 #

在Django项目中使用logging功能时，发送2-3次请求后日志文件出现损坏。环境信息如下：

• Python版本：3.6.8
• Django版本：3.2.3
• 部署方式：服务器用uWSGI，本地Mac使用PyCharm 2020.3.5开发
• 已注释项目中的多线程代码

现有日志配置 #

settings.py中的LOGGING配置 #

LOGGING = {
    'version': 1,
    'disable_existing_loggers': True,
    'formatters': {
        'standard': {
            'format': '%(asctime)s %(levelname)-8s [%(pathname)s:%(lineno)d] [%(funcName)s] [%(message)s]'
        }
    },
    'handlers': {
        'console_handler': {
            'level': 'DEBUG',
            'class': 'logging.StreamHandler',
            'formatter': 'standard',
        },
        'info_handler': {
            'level': 'INFO',
            'class': 'logging.handlers.TimedRotatingFileHandler',
            'formatter': 'standard',
            'filename': os.path.join(INFO_LOG_DIR, 'info.log'),
            'when': 'midnight',
            'backupCount': 30,
            'encoding': 'UTF-8',
        },
        'error_handler': {
            'level': 'ERROR',
            'class': 'logging.handlers.TimedRotatingFileHandler',
            'formatter': 'standard',
            'filename': os.path.join(ERROR_LOG_DIR, 'error.log'),
            'when': 'midnight',
            'backupCount': 30,
            'encoding': 'UTF-8',
        },
        'homework': {
            'level': 'DEBUG',
            'class': 'logging.handlers.RotatingFileHandler',
            'formatter': 'standard',
            'filename': os.path.join(HOMEWORK_LOG_DIR, 'homework.log'),
            'maxBytes': 1024 * 1024 * 10,
            'backupCount': 100,
            'encoding': 'UTF-8',
        }
    },
    'loggers': {
        'data_analysis': {
            'handlers': ['console_handler', 'info_handler', 'error_handler'],
            'level': 'DEBUG',
            'propagate': True,
        },
        'homework': {
            'handlers': ['homework', 'console_handler'],
            'level': 'DEBUG',
            'propagate': True,
        }
    },
}

业务代码中获取日志对象 #

log = logging.getLogger("data_analysis")

测试现象 #

• 当日志格式变量数≤3时（如'format': '%(asctime)s %(pathname)-8s %(message)s'），日志文件正常；增加变量后（如包含levelname、funcName等），3次请求后必损坏。
• 跨平台表现差异：Windows环境使用复杂格式无问题，Mac环境仅支持简单格式；服务器环境日志正常，本地Mac+PyCharm问题复现。

可能原因与解决方案 #

核心原因 #

本地Mac环境下，PyCharm的文件监控机制与日志处理器的文件操作存在竞争，复杂日志格式需要更多IO操作，加剧了文件句柄冲突，最终导致日志文件损坏。

具体修复步骤 #

1. 给文件日志处理器添加延迟初始化
   在TimedRotatingFileHandler和RotatingFileHandler的配置中添加'delay': True，让处理器在第一次写入日志时才打开文件，避免提前占用文件句柄：

   'info_handler': {
       # 原有配置...
       'delay': True,
   },
   'error_handler': {
       # 原有配置...
       'delay': True,
   },
   'homework': {
       # 原有配置...
       'delay': True,
   }
   

2. 启用文件处理器的线程安全锁
   添加'locking': True参数，确保日志写入时的线程安全，避免多进程/线程同时写入导致的文件损坏：

   'info_handler': {
       # 原有配置...
       'locking': True,
   },
   'error_handler': {
       # 原有配置...
       'locking': True,
   },
   'homework': {
       # 原有配置...
       'locking': True,
   }
   

3. 调整PyCharm的文件监控设置

   • 打开PyCharm的Settings > Appearance & Behavior > System Settings > Synchronization，取消勾选"Sync files on frame activation"和"Sync files automatically"。
   • 右键日志文件所在目录，选择Mark Directory as > Excluded，让PyCharm不再监控该目录的文件变化。

4. 明确指定文件写入模式
   在文件处理器配置中添加'mode': 'a'，确保以追加模式写入日志：

   'info_handler': {
       # 原有配置...
       'mode': 'a',
   }
   

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