0

Есть сервис на Django (DRF), в котором настроена подсистема логирования. Также в сервисе есть Celery-воркер, который выполняет некоторую задачу. Я хочу настроить логирование таким образом, чтобы все логи (и Django, и Celery) сохранялись в .log-файлах, при этом чтобы файлы "прокручивались" с помощью RotatingFileHandler, чтобы не засорять дисковое пространство. Сразу скажу, что я новичок в логировании в Django.

Настройки LOGGING в файле settings.py:

# Настройки логирования.
LOGGING = {
    'version': 1,
    'disable_existing_loggers': False,
    'formatters': {
        'default': {
            'format': '[{levelname}]-[{asctime}]-[{module}]-[{process:d}]-[{thread:d}]: {message}',
            'style': '{',
        },
    },
    'handlers': {
        'applications_logfile': {
            'level': 'INFO',
            'class': 'logging.handlers.RotatingFileHandler',
            'formatter': 'default',
            'filename': LOGS_DIR / 'applications/applications.log',
            'maxBytes': 300,
            'backupCount': 5,
        },
        'celery_worker_logfile': {
            'level': 'INFO',
            'class': 'logging.handlers.RotatingFileHandler',
            'formatter': 'default',
            'filename': LOGS_DIR / 'celery/worker.log',
            'maxBytes': 300,
            'backupCount': 5,
        },
    },
    'loggers': {
        'celery': {
            'level': 'INFO',
            'handlers': ['celery_worker_logfile'],
        },
        'api.application_handler.views': {
            'level': 'INFO',
            'handlers': ['applications_logfile'],
        },
    },
}

Настройка логирования в файле celery.py:

# Настройка логирования для Celery. Используем настройки логирования проекта.
@setup_logging.connect
def config_loggers(*args, **kwargs) -> None:
    from logging.config import dictConfig
    from django.conf import settings

    dictConfig(settings.LOGGING)

Также я отключил захват корневого регистратора для Celery:

# Настройки Celery.
CELERY_BROKER_URL = config('CELERY_BROKER_URL')
CELERYD_HIJACK_ROOT_LOGGER = False

Проблема заключается в том, что когда какой-либо прокручиваемый .log-файл достигает максимального размера и наступает момент, когда python пытается сделать прокрутку файлов, это не срабатывает и появляется следующая ошибка: PermissionError: [WinError 32] Процесс не может получить доступ к файлу, так как этот файл занят другим процессом. Что в воркере, что в django.

Причина. После долгих изучений данного поведения, я понял, что процесс django держит .log-файл, в который пишет celery-воркер, в celery-воркер в свою очередь держит .log-файл, в который пишет процесс django. "Прокручивание" (ротация) .log-файлов осуществляется через создании пустого .log-файла, в который пишутся логи, и переименовании старого .log-файла. Вот в этом-то и есть проблема. Ни один процесс не может переименовать файл из-за того, что он используется другим процессом.

Что я пробовал сделать. Я пробовал полностью разделить настройки логирования celery и django, убрав все настройки для celery из settings.py и прописав их в celery.py, чтобы два процесса вообще никак не трогали файлы друг друга.

settings.py:

# Настройки логирования.
LOGGING = {
    'version': 1,
    'disable_existing_loggers': False,
    'formatters': {
        'default': {
            'format': '[{levelname}]-[{asctime}]-[{module}]-[{process:d}]-[{thread:d}]: {message}',
            'style': '{',
        },
    },
    'handlers': {
        'applications_logfile': {
            'level': 'INFO',
            'class': 'logging.handlers.RotatingFileHandler',
            'formatter': 'default',
            'filename': LOGS_DIR / 'applications/applications.log',
            'maxBytes': 300,
            'backupCount': 5,
        },
    },
    'loggers': {
        'api.application_handler.views': {
            'level': 'INFO',
            'handlers': ['applications_logfile'],
        },
    },
}

celery.py

# Настройка логирования для Celery.
@setup_logging.connect
def config_loggers(*args, **kwargs) -> None:
    logger = logging.getLogger('celery')
    logger.setLevel(logging.INFO)
    formatter = logging.Formatter(
        fmt='[{levelname}]-[{asctime}]-[{module}]-[{process:d}]-[{thread:d}]: {message}',
        style='{',
    )
    handler = handlers.RotatingFileHandler(
        filename=settings.LOGS_DIR / 'celery/worker.log',
        maxBytes=300,
        backupCount=5,
    )
    handler.setFormatter(formatter)
    logger.addHandler(handler)

После этого процесс django больше не держал .log-файл, в который пишет воркер, и тот успешно вращался! Только вот почему-то celery-воркер до сих пор держит .log-файл, в который пишет процесс django, и тот не вращается и падает с ошибкой...

Я видел множество подобных проблем, но не нашел подходящего решения для себя. Информация везде разная, везде разные варианты, а задача довольно тривиальная, на мой взгляд, и наверняка должна иметь хорошее решение.

Заранее спасибо.

UPD.1: Я подозреваю, что все-таки celery как-то загружает в себя настройки, которые прописаны в LOGGING. Когда я убрал строку os.environ.setdefault('DJANGO_SETTINGS_MODULE', 'company.settings') из celery.py, процесс воркера больше не держал .log-файл, в который пишет процесс django (разумеется, и задачи автоматически не находились, я это сделал просто ради проверки).

UPD.2:

Запуск сервера django: python manage.py runserver --noreload.

Запуск celery-воркера: celery -A company worker --loglevel=info -P eventlet (я использую win10).

1 ответ 1

0

Я нашел ответ на свой вопрос!

В общем, все дело в том, что когда мы прописываем строчку os.environ.setdefault('DJANGO_SETTINGS_MODULE', 'company.settings') в celery.py, процесс celery-воркера получает модуль logging (который является singleton'ом) со всеми настройками django и LOGGING из settings.py. Поэтому процесс django и celery-воркера имеют общие настройки logging (celery только еще своего добавляет). Из-за этого они захватывают файлы логов друга друга. Так вот собственно решение. Все дело в том, что windows запрещает переименовывать файлы (при ротации логов), если файл занят другим процессом, а линукс - нет :) Так что все настройки логирования celery можно спокойно прописывать в settings.py, но если запускать это дело под linux'ом.

Чем это может быть опасно

В моем случае у меня для каждого процесса свои файлы логов, что логично и правильно. Однако один процесс может удалить/переименовать файл, который использует в это время другой процесс. Другой процесс об этом не узнает и могут быть большие проблемы. Но если процессы работают только со своими файлами, не трогая другие, то проблем не будет.

Ваш ответ

By clicking “Отправить ответ”, you agree to our terms of service and acknowledge that you have read and understand our privacy policy and code of conduct.

Всё ещё ищете ответ? Посмотрите другие вопросы с метками или задайте свой вопрос.