一，Django日志的基础知识
在 Django 中使用 Python 的标准库 logging 模块来记录日志，关于 logging的配置，我这里不做过多介绍，只写其中最重要的四个部分：Loggers、Handlers、Filters 和 Formatters。
1，Loggers
1）Logger 即记录器，是日志系统的入口。它有三个重要的工作：
- 向应用程序（也就是你的项目）公开几种方法，以便运行时记录消息
- 根据传递给 Logger 的消息的严重性，确定消息是否需要处理
- 将需要处理的消息传递给所有感兴趣的处理器 Handler
2） 每一条写入 Logger 的消息都是一条日志记录，每一条日志记录都包含级别，代表对应消息的严重程度。常用的级别如下：
- DEBUG：排查故障时使用的低级别系统信息，通常开发时使用
- INFO：一般的系统信息，并不算问题
- WARNING：描述系统发生小问题的信息，但通常不影响功能
- ERROR：描述系统发生大问题的信息，可能会导致功能不正常
- CRITICAL：描述系统发生严重问题的信息，应用程序有崩溃的风险
3） 当 Logger 处理一条消息时，会将自己的日志级别和这条消息配置的级别做对比。如果消息的级别匹配或者高于 Logger 的日志级别，它就会被进一步处理，否则这条消息就会被忽略掉。
4） 当 Logger 确定了一条消息需要处理之后，会把它传给 Handler。
2，Handlers
Handler 即处理器，它的主要功能是决定如何处理 Logger 中的每一条消息，比如把消息输出到屏幕、文件或者 Email 中。
和 Logger 一样，Handler 也有级别的概念。如果一条日志记录的级别不匹配或者低于 Handler 的日志级别，则会被 Handler 忽略。
一个 Logger 可以有多个 Handler，每一个 Handler 可以有不同的日志级别。这样就可以根据消息的重要性不同，来提供不同类型的输出。例如，你可以添加一个 Handler 把 ERROR 和 CRITICAL 消息发到你的 Email，再添加另一个 Handler 把所有的消息（包括 ERROR 和 CRITICAL 消息）保存到文件里。
3，Filters
Filter 即过滤器。在日志记录从 Logger 传到 Handler 的过程中，使用 Filter 来做额外的控制。例如，只允许某个特定来源的 ERROR 消息输出。
Filter 还被用来在日志输出之前对日志记录做修改。例如，当满足一定条件时，把日志级别从 ERROR 降到 WARNING 。
Filter 在 Logger 和 Handler 中都可以添加，多个 Filter 可以链接起来使用，来做多重过滤操作。
4，Formaters
Formatter 即格式化器，主要功能是确定最终输出的形式和内容。
二，实现方式
1，使用django-logging模块的class - RotatingFileHandler
1) 实现效果
设置RotatingFileHandler的maxBytes与backupCount，这两个参数默认是0。 当两个参数都不为0时，会执行rallover过程：
log文件大小接近maxBytes时，新建一个文件作为log的输出，旧的文件会被加上类似’.1’、’.2’的后缀。 举个例子，如果backupCount=5，log file定义的名字为app.log，你会得到app.log, app.log.1, app.log.2 一直到 app.log.5。 然而被写入日志的永远是app.log，写满了之后重命名为app.log.1，如果app.log.1存在，app.log.1会先被重名名为app.log.2，依此类推。 另外，如果app.log.5存在，它会被删除。
2）实现代码
在settings中配置以下代码：
#LOGGING_DIR 日志文件存放目录
LOGGING_DIR = "logs" # 日志存放路径
if not os.path.exists(LOGGING_DIR):
os.mkdir(LOGGING_DIR)
import logging
LOGGING = {
'version': 1,
'disable_existing_loggers': False,
'formatters': { #格式化器
'standard': {
'format': '[%(levelname)s][%(asctime)s][%(filename)s][%(funcName)s][%(lineno)d] > %(message)s'
},
'simple': {
'format': '[%(levelname)s]> %(message)s'
},
},
'filters': {
'require_debug_true': {
'()': 'django.utils.log.RequireDebugTrue',
},
},
'handlers': {
'console': {
'level': 'DEBUG',
'filters': ['require_debug_true'],
'class': 'logging.StreamHandler',
'formatter': 'simple'
},
'default': { # 用于文件输出
'level': 'INFO', # 输出日志等级
'class': 'logging.handlers.RotatingFileHandler', # 日志类型
'filename': '%s/django.log' % LOGGING_DIR, # 具体日志文件的名字
'maxBytes': 1024 * 1024 * 2, # 日志大小
'backupCount': 1, # 备份数量
'formatter':'standard', # 输出日志格式
'encoding': 'utf-8', # 输出日志编码
},
'error': {
'level': 'ERROR',
'class': 'logging.handlers.RotatingFileHandler',
'filename': '%s/error.log' % LOGGING_DIR,
'maxBytes': 1024 * 1024 * 2,
'backupCount': 2,
'formatter': 'standard',
'encoding': 'utf-8',
},
'modify': {
'level': 'INFO',
'class': 'logging.handlers.RotatingFileHandler', # 保存到文件，自动切
'filename': '%s/modify.log' % LOGGING_DIR,
'maxBytes': 1024 * 1024 * 5, # 日志大小 5M
'backupCount': 4,
'formatter': 'standard',
'encoding': "utf-8"
}
},
'loggers': { #日志分配到哪个handlers中
'mydjango': {
'handlers': ['console','default','error'], # 上线之后可以把'console'移除
'level':'DEBUG',
'propagate': True, # 向不向更高级别的logger传递
},
'modify': { # 名为 'modify'的logger还单独处理
'handlers': ['console', 'default', 'error', "modify"],
'level': 'DEBUG',
'propagate': False,
},
}
}
2，使用django-logging模块的class - TimedRotatingFileHandler
1）实现代码
LOGGING = {
'version': 1,
'disable_existing_loggers': False,
'formatters': {
'verbose': {
'format': '[%(asctime)s] [%(levelname)s] %(message)s'
},
},
'handlers': {
# 输出日志的控制台
'console': {
'level': 'INFO',
'class': 'logging.StreamHandler',
'formatter': 'verbose'
},
# 'default': {
# 'level': 'INFO',
# 'class': 'logging.handlers.TimedRotatingFileHandler',
# 'filename': '%s/django.log' % LOGGING_DIR, # 日志的文件名
# # TimedRotatingFileHandler的参数
# # 目前设定每天一个日志文件
# # 'S' | 秒
# # 'M' | 分
# # 'H' | 时
# # 'D' | 天
# # 'W0'-'W6' | 周一至周日
# # 'midnight' | 每天的凌晨
# 'when': 'midnight', # 间间隔的类型
# 'interval': 1, # 时间间隔
# 'backupCount': 100, # 能留几个日志文件;过数量就会丢弃掉老的日志文件
# 'formatter': 'standard', # 日志文本格式
# 'encoding': 'utf-8', # 日志文本编码
# },
# 输出日志到文件，按日期滚动
'file': {
'level': 'DEBUG',
'class': 'logging.handlers.TimedRotatingFileHandler',
# TimedRotatingFileHandler的参数
# 参照https://docs.python.org/3/library/logging.handlers.html#timedrotatingfilehandler
# 目前设定每天一个日志文件
'filename': 'logs/manage.log',
'when': 'midnight',
'interval': 1,
'backupCount': 100,
'formatter': 'verbose'
},
# 发送邮件，目前腾讯云、阿里云的服务器对外发送邮件都有限制，暂时不使用
'email': {
'level': 'ERROR',
'class': 'django.utils.log.AdminEmailHandler',
'include_html': True,
}
},
'loggers': {
# 不同的logger
'django': {
'handlers': ['console', 'file'],
'level': 'INFO',
'propagate': True,
},
},
}
2）RotatingFileHandler 和 TimedRotatingFileHandler在多进程环境下会出现异常
异常如下：
- 日志写入错乱；
- 日志并没有按天分割，而且还会丢失。
出现异常的原因为：
Django logging 是基于 Python logging 模块实现的，logging 模块是线程安全的，但不能保证多进程安全。
以下为对异常的详细描述：
下面来详细描述一下这个异常过程，假设我们每天生成一个日志文件 error.log，每天凌晨进行日志分割。那么，在单进程环境下是这样的：
生成 error.log 文件；
写入一天的日志；
零点时，判断 error.log-2020-05-15 是否存在，如果存在则删除；如果不存在，将 error.log 文件重命名为 error.log-2020-05-15；
重新生成 error.log 文件，并将 logger 句柄指向新的 error.log。
再来看看多进程的情况：
生成 error.log 文件；
写入一天的日志；
零点时，1 号进程判断 error.log-2020-05-15 是否存在，如果存在则删除；如果不存在，将 error.log 文件重命名为 error.log-2020-05-15；
此时，2 号进程可能还在向 error.log 文件进行写入，由于写入文件句柄已经打开，所以会向 error.log-2020-05-15 进行写入；
2 号进程进行文件分割操作，由于 error.log-2020-05-15 已经存在，所以 2 号进程会将它删除，然后再重命名 error.log，这样就导致了日志丢失；
由于 2 号进程将 error.log 重命名为 error.log-2020-05-15，也会导致 1 号进程继续向 error.log-2020-05-15 写入，这样就造成了写入错乱。
3，为解决多进程问题，有如下两种方案
1) ConcurrentLogHandler
pip install ConcurrentLogHandler
# settings.py
LOGGING = {
...
'handlers': {
...
'file': {
'level': 'INFO',
'class': 'cloghandler.ConcurrentRotatingFileHandler',
'filename': os.path.join(LOGS_DIR, 'app.log'),
'formatter': 'verbose',
'maxBytes': 1024,
'backupCount': 5
},
...
}
...
}
此包的最后更新时间是 2013.7，可见很久没有人维护了。之后在这个官网又找到了这个包的升级版本concurrent-log-handler，即下面这个包
2）concurrent-log-handler
pip install concurrent-log-handler
在LOGGING中，用concurrent_log_handler.ConcurrentRotatingFileHandler代替logging.RotatingFileHandler
# settings.py
LOGGING = {
...
'handlers': {
...
'file': {
'level': 'INFO',
'class': 'concurrent_log_handler.ConcurrentRotatingFileHandler',
'filename': os.path.join(LOGS_DIR, 'app.log'),
'formatter': 'verbose',
'maxBytes': 1024,
'backupCount': 5
},
...
}
...
}
这个包目前还在有人维护。此包不足之处：
只有RotatingFileHandler的改动，也就是说，只对大小分割文件的handler 做了优化，并没有对TimeRotatingFileHandler优化。这个包通过加锁的方式实现了多进程安全，并且可以在日志文件达到特定大小时，分割文件，但是不支持按时间分割。
三，自定义logger类
以上几种方法均无法完全实现django配置多进程按日期分割处理日志。我们考虑自定义实现。
1， 重写 TimedRotatingFileHandler
通过上面的分析可以知道，出问题的点就是发生在日志分割时，一是删文件，二是没有及时更新写入句柄。
所以针对这两点，我的对策就是：一是去掉删文件的逻辑，二是在切割文件时，及时将写入句柄更新到最新。
import os
import time
from logging.handlers import TimedRotatingFileHandler
class CommonTimedRotatingFileHandler(TimedRotatingFileHandler):
@property
def dfn(self):
currentTime = int(time.time())
# get the time that this sequence started at and make it a TimeTuple
dstNow = time.localtime(currentTime)[-1]
t = self.rolloverAt - self.interval
if self.utc:
timeTuple = time.gmtime(t)
else:
timeTuple = time.localtime(t)
dstThen = timeTuple[-1]
if dstNow != dstThen:
if dstNow:
addend = 3600
else:
addend = -3600
timeTuple = time.localtime(t + addend)
dfn = self.rotation_filename(self.baseFilename + "." + time.strftime(self.suffix, timeTuple))
return dfn
def shouldRollover(self, record):
"""
是否应该执行日志滚动操作：
1、存档文件已存在时，执行滚动操作
2、当前时间 >= 滚动时间点时，执行滚动操作
"""
dfn = self.dfn
t = int(time.time())
if t >= self.rolloverAt or os.path.exists(dfn):
return 1
return 0
def doRollover(self):
"""
执行滚动操作
1、文件句柄更新
2、存在文件处理
3、备份数处理
4、下次滚动时间点更新
"""
if self.stream:
self.stream.close()
self.stream = None
# get the time that this sequence started at and make it a TimeTuple
dfn = self.dfn
# 存档log 已存在处理
if not os.path.exists(dfn):
self.rotate(self.baseFilename, dfn)
# 备份数控制
if self.backupCount > 0:
for s in self.getFilesToDelete():
os.remove(s)
# 延迟处理
if not self.delay:
self.stream = self._open()
# 更新滚动时间点
currentTime = int(time.time())
newRolloverAt = self.computeRollover(currentTime)
while newRolloverAt <= currentTime:
newRolloverAt = newRolloverAt + self.interval
# If DST changes and midnight or weekly rollover, adjust for this.
if (self.when == 'MIDNIGHT' or self.when.startswith('W')) and not self.utc:
dstAtRollover = time.localtime(newRolloverAt)[-1]
dstNow = time.localtime(currentTime)[-1]
if dstNow != dstAtRollover:
if not dstNow: # DST kicks in before next rollover, so we need to deduct an hour
addend = -3600
else: # DST bows out before next rollover, so we need to add an hour
addend = 3600
newRolloverAt += addend
self.rolloverAt = newRolloverAt
在 settings handles 中引入上面 class 即可。
扫一扫
5718
被折叠的 条评论
为什么被折叠?
到【灌水乐园】发言
