Почему django logging-config не применяется ко всем экземплярам logger? - PullRequest
Новая
       40

Почему django logging-config не применяется ко всем экземплярам logger?

1 голос
/ 28 апреля 2020

Python 3.8, Django 3.0

Я использую docker-compose logs для отображения и обработки журналов контейнера с помощью django. Чтобы убедиться, что все выходные данные имеют одинаковый формат, я определяю LOGGING внутри settings.py

LOGGING = {
    'version': 1,
    'disable_existing_loggers': False,
    'formatters': {
        'detailed': {
            'format': '{levelname} [{asctime}]{name} :  {message}',
            'style': '{',
        },
    },
    'handlers': {
            'console': {
                'level': env('DJANGO_LOG_LEVEL'),
                'class': 'logging.StreamHandler',
                'formatter': 'detailed'
            },
    },
    'loggers': {
        '': {
            'handlers': ['console'],
            'propagate': False,
            'level': 'DEBUG',
        },
        'django': {
            'handlers': ['console'],
            'propagate': False,
            'level': env('DJANGO_LOG_LEVEL'),
        },
        # django.template and django.backends must not use DEBUG-level, since it is buggy
        'django.template': {
            'propagate': True,
            'level': 'INFO',
        },
        'django.db.backends': {
            'propagate': True,
            'level': 'INFO',
        },
        # use same format for logs from uvicorn
        'uvicorn': {
            'handlers': ['console'],
            'propagate': False,
            'level': 'INFO',
        },
    }
}

Однако при запуске контейнера я получаю следующий вывод в журналах: 

django_1    | INFO [2020-04-28 16:00:25,482]uvicorn.error :  Started server process [16]
django_1    | INFO [2020-04-28 16:00:25,482]uvicorn.error :  Waiting for application startup.
django_1    | INFO [2020-04-28 16:00:25,482]uvicorn.error :  ASGI 'lifespan' protocol appears unsupported.
django_1    | INFO [2020-04-28 16:00:25,482]uvicorn.error :  Application startup complete.
django_1    | WARNING:  Detected file change in 'myproject/settings.py'. Reloading...
django_1    | INFO [2020-04-28 16:04:01,080]uvicorn.error :  Shutting down
django_1    | INFO [2020-04-28 16:04:01,180]uvicorn.error :  Finished server process [16]
django_1    | INFO [2020-04-28 16:04:01,888]uvicorn.error :  Started server process [18]
django_1    | INFO [2020-04-28 16:04:01,888]uvicorn.error :  Waiting for application startup.
django_1    | INFO [2020-04-28 16:04:01,888]uvicorn.error :  ASGI 'lifespan' protocol appears unsupported.
django_1    | INFO [2020-04-28 16:04:01,888]uvicorn.error :  Application startup complete.

Как видите, uvicorn использует указанный мной logging.config. Однако этот один вызов WARNING: Detected file change in 'myproject/settings.py'. Reloading... не следует шаблону. Это очень странно, потому что сообщение вызывается внутри lib/python3.8/site-packages/uvicorn/supervisors/statreload.py с 

logger = logging.getLogger("uvicorn.error")
# ...
# ...
# ...
display_path = os.path.normpath(filename)
if Path.cwd() in Path(filename).parents:
   display_path = os.path.normpath(os.path.relpath(filename))
message = "Detected file change in '%s'. Reloading..."
logger.warning(message, display_path)

По крайней мере, именно поэтому я думаю, что это предупреждение исходит. Так почему же мой конфиг не применим к этому?

При попытке определить источник проблемы я обнаружил еще одну любопытную вещь:

Когда я вызываю регистратор прямо внутри settings.py также не применяется конфигурация: 

import logging
logger = logging.getLogger("django")
logger.warning("hello")

будет просто отображать 

WARNING:  hello

Но когда я использую тот же код в представлении myapp/views.py, я получаю 

django_1    | INFO [2020-04-28 16:14:07,960]uvicorn.error :  Application startup complete.
django_1    | WARNING [2020-04-28 16:14:12,789]django :  hello
django_1    | INFO [2020-04-28 16:14:12,942]uvicorn.access :  172.20.0.5:43470 - "GET / HTTP/1.0" 200

Так что, похоже, проблема root, возможно, не в uvicorn, а в том, что конфигурация логирования применяется только к некоторым конкретным c модулям?

Что именно здесь не так? Почему это ведет себя так странно? Или я что-то не так понимаю?

...