问题 Python在Django网站上记录RotatingFileHandler的问题


我有一个django支持的网站,我使用标准的日志记录模块来跟踪网络活动。

该日志通过RotatingFileHandler完成,该配置有10个日志文件,每个文件1000000字节。日志系统可以工作,但这是我得到的日志文件:

-rw-r--r-- 1 apache      apache          83 Jul 23 13:30 hr.log
-rw-r--r-- 1 apache      apache      446276 Jul 23 13:03 hr.log.1
-rw-r--r-- 1 apache      apache      999910 Jul 23 06:00 hr.log.10
-rw-r--r-- 1 apache      apache         415 Jul 23 16:24 hr.log.2
-rw-r--r-- 1 apache      apache      479636 Jul 23 16:03 hr.log.3
-rw-r--r-- 1 apache      apache         710 Jul 23 15:30 hr.log.4
-rw-r--r-- 1 apache      apache      892179 Jul 23 15:03 hr.log.5
-rw-r--r-- 1 apache      apache         166 Jul 23 14:30 hr.log.6
-rw-r--r-- 1 apache      apache      890769 Jul 23 14:03 hr.log.7
-rw-r--r-- 1 apache      apache      999977 Jul 23 12:30 hr.log.8
-rw-r--r-- 1 apache      apache      999961 Jul 23 08:01 hr.log.9

你可以看到它是一团糟。上次日志已写入文件hr.log.2(7月23日16:24) 而不是hr.log,和 记录文档 说:

[...]例如,如果backupCount为5,基本文件名为app.log,则会获得app.log,app.log.1,app.log.2,最多为app.log.5。 正在写入的文件始终是app.log。填写此文件后,它将关闭并重命名为app.log.1,如果存在app.log.1,app.log.2等文件,则将它们重命名为app.log.2,app。 log.3等。

我究竟做错了什么?


我的日志配置文件是:

logger.conf:

[loggers]
keys=root

[handlers]
keys=fileHandler

[formatters]
keys=simple

#--------------------------------------------------------------------
# Formatters
[formatter_simple]
format=%(asctime)s - %(name)s - %(levelname)s - %(message)s

#--------------------------------------------------------------------
# Handlers
[handler_fileHandler]
class=handlers.RotatingFileHandler
level=DEBUG
formatter=simple
args=("/data/django/hr/hr.log",'a',1000000,10)

#--------------------------------------------------------------------
# Loggers
[logger_root]
level=DEBUG
handlers=fileHandler

和我的python模块来设置日志系统是:

logger.py

import os, logging

# Load config file
logger_config_file = \
    os.path.join(os.path.abspath(os.path.dirname(__file__)), 'logger.conf')
logging.config.fileConfig(logger_config_file)

# Create logger
logger = logging.getLogger('hr_Logger')

# Log start message
logger.info("Logging system started")

然后,在我的views.py的顶部,我有:

import logging
from hr import logger

log = logging.getLogger('hr.views')
log.info('Load hr.views')

[...]

12457
2017-07-23 15:47


起源

我尝试使用您的代码本地设置,它工作正常。我不禁注意到时间戳主要是:30和:03。特别是从14:03开始,它看起来好像是日志文件在应用程序之外旋转了。一个想法:您确定这是唯一配置的日志记录吗?看起来有点像你有一些其他日志代码保持打开文件句柄。当应用程序启动时,其他句柄指向hr.log,此后它被旋转到hr.2。 - Patrice Neff
所以...你不是说日志系统坏了,只是时间戳已经改变了?日志文件是否以正确的顺序旋转?我刚刚通过相同的方法检查了我的旋转日志上的时间戳,它们的顺序正确。我没有处理日志的任何日志处理。看起来你可能有一个可能触及文件的周期性任务? - Kekoa
@Kekoa正如你所说,日志系统没有被破坏,它只是没有按预期工作。不幸的是,我不再在该项目上工作了,我无法测试任何可能的建议。谢谢。 - ssoler


答案:


当你的代码运行多个precesses时,我发现了这种行为。

不幸的是,没有完美的选择。

您可以合并的一些想法是:

  • 使用WatchedFileHandler(2.6中的新增功能)并使用外部程序作为logrotate旋转
  • 使用syslog或其他日志聚合服务器
  • 使用python日志聚合 哨兵  - 这对django特别有用,因为您不仅可以记录日志消息,还可以记录具有完整堆栈跟踪和404的异常。

7
2018-03-15 16:00





也许这值得考虑 http://pypi.python.org/pypi/ConcurrentLogHandler/0.8.3


6
2017-08-05 04:43



该模块已过期(最新更新时间为2009-11-02) - Taha Jahangir


Google出现了这个答案:

http://bytes.com/topic/python/answers/643884-rotatingfilehandler-bugs-errors-general-logging-question#post2552392

可能是你有多个进程运行记录器?也许多个应用程序记录到相同的文件?


0
2018-03-04 23:02