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

简介

大量过时的日志会占用硬盘空间，甚至长时间运行不注意会占满硬盘导致宕机，那么就可以使用内建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开启四个进程启动项目时未出现此错误，但并不代表没有此问题，因为我没有进行并发测试。

解决办法

开发环境

本地开发的话可以停止服务，然后删除旧的日志再启动

python manage.py runserver

增加 --reload参数不启用自动重启，也就不会又两个进程，但是本地开发不能自动重启稍有不便

生产环境

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

参考

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