Я написал статью раньшеКак изящно войти в Django, я думал, что после того, как код появится в сети, я смогу с радостью прочитать лог и проанализировать проблему через лог, но реальность всегда отличается от воображения, два аномальных явления махнули руками и ударили меня по лицу.
Два исключения заключаются в следующем:
- Расстройство записи журнала;
- Логи не разбиваются по дням и теряются.
Поискав некоторую информацию в Интернете, я нашел причину:
Ведение журнала Django реализовано на основе модуля ведения журнала Python, который является потокобезопасным, но не безопасным для нескольких процессов. Мой проект Django запускает несколько процессов через uwsgi, поэтому возникают две вышеуказанные проблемы.
Опишем этот аномальный процесс подробнее, допустим, мы каждый день генерируем лог-файл error.log и разбиваем лог каждое утро. Итак, в однопроцессной среде это выглядит так:
- Создать файл error.log;
- Ведите дневник дня;
- В нуле оцените, существует ли error.log-2020-05-15, и удалите его, если он есть, если не существует, переименуйте файл error.log в error.log-2020-05-15;
- Восстановите файл error.log и укажите дескриптор регистратора на новый error.log.
Давайте посмотрим на ситуацию с несколькими процессами:
- Создать файл error.log;
- Ведите дневник дня;
- В 0:00 процесс №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, что вызвало путаницу при записи.
Причина ясна, так как же решение? Два варианта:
Использование пакета concurrent-log-handler
Этот пакет реализует многопроцессорную безопасность путем блокировки и может разделить файл журнала, когда он достигает определенного размера, но не поддерживает разделение по времени.
Исходный код пакета я внимательно не изучал, поэтому вдаваться в подробности не могу, если интересно, то можете найти сами.
Поскольку мои потребности разделены по времени, очевидно, что это не может быть использовано, поэтому напишите это сами.
Переопределить 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
Просто импортируйте указанный выше класс в настройки handles.
Производственная среда находится в сети уже две недели и работает стабильно без каких-либо исключений.
над.
Справочная документация:
Краткое описание.com/fear/665694966…
Технический блог:
GitHub.com/Делайте это с душой/Особые…
В то же время, вы также можете обратить внимание на мой публичный аккаунт WeChat.AlwaysBeta, вас ждет еще больше захватывающего контента.