@mu-mu

Как отлаживать связку Nginx+Supevisor+Gunicorn+Django?

Имеется VPS сервер, на нём развернута связка Nginx+Supevisor+Gunicorn+Django.
В целом всё работает, но есть url mysite.com/ru/checkout/shipping-address/ который в проде не работает.
Симптоматика следующая - забиваем в браузере mysite.com/ru/checkout/shipping-address/, сервер на запрос ничего не отвечает 30 секунд, а потом возвращает 500.html
Конфиг nginx:
upstream mysite.com {
    server localhost:12345 fail_timeout=0;
}

server {
    listen 80;
    server_name mysite.com;
    return 301 https://$host$request_uri;
}

server {
    listen 443 ssl;
    server_name mysite.com;
    ssl_certificate /etc/letsencrypt/live/mysite.com/fullchain.pem;
    ssl_certificate_key /etc/letsencrypt/live/mysite.com/privkey.pem;
    ssl_prefer_server_ciphers on;

    client_max_body_size 100m;
    access_log  /var/log/nginx/mysite_access.log;
    error_log  /var/log/nginx/mysite_error.log;
    keepalive_timeout 5;

    root /var/www/html/django-oscar-mysite/static_content;

    location / {
        proxy_pass http://mysite.com;
    }

    error_page 500 502 503 504 /500.html;
    location = /500.html {
        root /var/www/html/django-oscar-mysite/static_content/static/html;
    }

    location ~ /.well-known {
        root /var/www/html;
        allow all;
    }

    location /static {
        autoindex on;
        alias /var/www/html/django-oscar-mysite/static_content/static/;
    }
    location /media {
        autoindex on;
        alias /var/www/html/django-oscar-mysite/static_content/media/;
    }
}

Конфиг supervisor:
[program:mysite_sv]
command=/var/www/html/django-oscar-mysite/venv/bin/gunicorn --bind 0.0.0.0:12345 wsgi --error-logfile /var/log/gunicorn/error.log --access-logfile /var/log/gunicorn/access.log --capture-output --log-level debug
directory=/var/www/html/django-oscar-mysite/
umask=022
autostart=true
autorestart=true
startsecs=10
startretries=2
exitcodes=0,2
stopsignal=TERM
stopwaitsecs=10
user=root

settings.py
...
LOGGING = {
    'version': 1,
    'disable_existing_loggers': False,
    'formatters': {
        'verbose': {
            'format': '%(levelname)s %(asctime)s %(module)s %(process)d %(thread)d %(message)s'
        },
    },
    'handlers': {
        'null': {
            'level': 'DEBUG',
            'class': 'logging.NullHandler',
        },
        'console': {
            'level': 'DEBUG',
            'class': 'logging.StreamHandler',
            'formatter': 'verbose'
        },
        'mail_admins': {
            'level': 'DEBUG',
            'class': 'django.utils.log.AdminEmailHandler',
        },
        'file1': {
            'level': 'DEBUG',
            'class': 'logging.FileHandler',
            'formatter': 'verbose',
            'filename': "/var/www/html/django-oscar-mysite/logs/file1.log"
        },
        'file2': {
            'level': 'DEBUG',
            'class': 'logging.FileHandler',
            'formatter': 'verbose',
            'filename': "/var/www/html/django-oscar-mysite/logs/file2.log"
        },
        'file3': {
            'level': 'DEBUG',
            'class': 'logging.FileHandler',
            'formatter': 'verbose',
            'filename': "/var/www/html/django-oscar-mysite/logs/file3.log"
        },
        'file4': {
            'level': 'DEBUG',
            'class': 'logging.FileHandler',
            'formatter': 'verbose',
            'filename': "/var/www/html/django-oscar-mysite/logs/file4.log"
        },
    },
    'loggers': {
        '': {
            'level': 'DEBUG',
            'handlers': ['file1']
        },
        'django': {
            'handlers': ['file2'],
            'level': 'DEBUG',
        },
        'django.server': {
            'handlers': ['file3'],
            'level': 'DEBUG',
            'propagate': False,
        },
        'django.request': {
            'handlers': ['file4'],
            'level': 'DEBUG',
            'propagate': False,
        },
    }
}

Что пишется в логах после открытия страницы с ошибкой:
/var/log/nginx/mysite_error.log
2023/01/24 21:12:02 [error] 93698#93698: *2 connect() failed (111: Unknown error) while connecting to upstream, client: 195.239.169.229, server: mysite.com, request: "GET /ru/checkout/shipping-address/ HTTP/1.1", upstream: "http://[::1]:12345/ru/checkout/shipping-address/", host: "mysite.com", referrer: "https://mysite.com/ru/basket/"
2023/01/24 21:12:32 [error] 93698#93698: *2 upstream prematurely closed connection while reading response header from upstream, client: 195.239.169.229, server: mysite.com, request: "GET /ru/checkout/shipping-address/ HTTP/1.1", upstream: "http://127.0.0.1:12345/ru/checkout/shipping-address/", host: "mysite.com", referrer: "https://mysite.com/ru/basket/"

/var/log/supervisor/supervisord.log
2023-01-24 21:11:56,456 CRIT Supervisor is running as root.  Privileges were not dropped because no user is specified in the config file.  If you intend to run as root, you can set user=root in the config file to avoid this message.
2023-01-24 21:11:56,456 INFO Included extra file "/etc/supervisor/conf.d/mysite_sv.conf" during parsing
2023-01-24 21:11:56,463 INFO RPC interface 'supervisor' initialized
2023-01-24 21:11:56,464 CRIT Server 'unix_http_server' running without any HTTP authentication checking
2023-01-24 21:11:56,465 INFO supervisord started with pid 93689
2023-01-24 21:11:57,469 INFO spawned: 'mysite_sv' with pid 93691
2023-01-24 21:12:07,878 INFO success: mysite_sv entered RUNNING state, process has stayed up for > than 10 seconds (startsecs)

/var/log/supervisor/mysite-stderr.log
пусто

/var/log/supervisor/mysite-stdout.log
пусто

/var/log/gunicorn/error.log
[2023-01-24 21:11:57 +0300] [93691] [INFO] Starting gunicorn 20.1.0
[2023-01-24 21:11:57 +0300] [93691] [DEBUG] Arbiter booted
[2023-01-24 21:11:57 +0300] [93691] [INFO] Listening at: http://0.0.0.0:12345 (93691)
[2023-01-24 21:11:57 +0300] [93691] [INFO] Using worker: sync
[2023-01-24 21:11:57 +0300] [93699] [INFO] Booting worker with pid: 93699
[2023-01-24 21:11:57 +0300] [93691] [DEBUG] 1 workers
[2023-01-24 21:12:02 +0300] [93699] [DEBUG] GET /ru/checkout/shipping-address/
[2023-01-24 21:12:32 +0300] [93691] [CRITICAL] WORKER TIMEOUT (pid:93699)
[2023-01-24 21:12:32 +0300] [93699] [INFO] Worker exiting (pid: 93699)

/var/www/html/django-oscar-mysite/logs/file1.log
пусто

/var/www/html/django-oscar-mysite/logs/file2.log
пусто

/var/www/html/django-oscar-mysite/logs/file3.log
пусто

/var/www/html/django-oscar-mysite/logs/file4.log
пусто

Примечание1: если запустить сервер в режиме DEBUG=True, то страница mysite.com/ru/checkout/shipping-address/ аналогично вернёт 500.html.
Примечание2: если открыть страницу сайта, которая корректно отображается, то в file1.log и file2.log попадают записи по исключениям в templates, то есть логи в принципе живые. Сначала думала, что где-то валится исключение, которое я не вижу, поэтому логи так подробила у django.
Я себе ситуацию вижу так: python с django ушли что-то делать и за 30 секунд не дали никакого ответа gunicorn, supervisor отчитался о проблеме nginx и тот вывесил страницу 500.html. Но что дальше делать у меня идей уже нет. На тестовом сервере всё работает без ошибок, проблема возникает только при развёртывании на боевом.
Посоветуйте по методологии, с какой стороны зайти к этой проблеме? Как её раскручивать?
  • Вопрос задан
  • 105 просмотров
Пригласить эксперта
Ваш ответ на вопрос

Войдите, чтобы написать ответ

Похожие вопросы