python日志轮转RotatingFileHandler在django中的一个bug

python基础

浏览数:125

2020-5-31

简介

大量过时的日志会占用硬盘空间,甚至长时间运行不注意会占满硬盘导致宕机,那么就可以使用内建logging模块根据文件大小(logging.handlers.RotatingFileHandler)或者时间(logging.handlers.TimedRotatingFileHandler)进行日志轮转。使用细节参考python官方文档

问题

在django中使用时通常如下(只截取了RotatingFileHandler部分配置示例):

LOGGING = {
    'version': 1,
    'disable_existing_loggers': True,
    'handlers': {
        'default': {
            'level':'DEBUG',
            'class':'logging.handlers.RotatingFileHandler',
            'filename': os.path.join(LOGDIR, LOGFILE),  # 或者直接写路径:'c:\logs\all.log',
            'maxBytes': 1024*1024*5,  # 5 MB
            'backupCount': 5,
        }
    }
}

以上配置时当文件大于5Mb时将当前日志重命名备份,新建一个空日志记录新日志。当备份日志达到5个时删除旧的备份文件。

当在python开发模式(manage.py runserver)时如果备份文件已经达到backupCount后会报错:

  • linux下:
Traceback (most recent call last):
  File "/usr/lib64/python2.7/logging/handlers.py", line 77, in emit
    self.doRollover()
  File "/usr/lib64/python2.7/logging/handlers.py", line 136, in doRollover
    os.rename(sfn, dfn)
OSError: [Errno 13] Permission denied
Logged from file utils.py, line 89
  • windows下
Traceback (most recent call last):
  File "F:\Python27\lib\logging\handlers.py", line 77, in emit
    self.doRollover()
  File "F:\Python27\lib\logging\handlers.py", line 142, in doRollover
    os.rename(self.baseFilename, dfn)
WindowsError: [Error 32] 
Logged from file utils.py, line 89

原因

这是由于django开发模式时会同时启动两个进程加载settings.py,导致日志文件占用后无法重命名或者删除

都知道django开发模式下如果有文件变动会自动重新启动,所以同时又两个进程,一个是程序正常运行的进程,另一个是用来监听变更并重启服务的进程,他们都会加载一遍settings.py,可以在settings.py中加print然后启动会看到控制台又两次输出。

我怀疑使用uwsgi等wsgi程序时的多进程也会导致此问题,但是我使用uwsgi开启四个进程启动项目时未出现此错误,但并不代表没有此问题,因为我没有进行并发测试。

解决办法

开发环境

  1. 本地开发的话可以停止服务,然后删除旧的日志再启动
  2. python manage.py runserver增加 –reload参数不启用自动重启,也就不会又两个进程,但是本地开发不能自动重启稍有不便

生产环境

  1. 推荐使用sentry、elk或者一些集中日志服务使用socket或者http方式记录日志

参考

https://stackoverflow.com/questions/26682413/django-rotating-file-handler-stuck-when-file-is-equal-to-maxbytes?answertab=votes#tab-top

作者:扑棱扑棱