Периодические ошибки 502 с nginx+gunicorn+django

За последние несколько недель мы получаем все больше и больше ошибок 502. В настоящее время наш стек — это nginx + gunicron + django на инстансе m1.large EC2, поддерживаемом небольшим инстансом RDS.

Кажется, они становятся более частыми по мере увеличения нагрузки запросов. Я увижу случайное 502 при использовании браузера, но наши сценарии командной строки, которые обращаются к API (Tasty Pie), обычно терпят неудачу при втором или третьем запросе. Однако, если я добавлю функцию сна в сценарий прямо перед тем, как он сделает запрос, это будет нормально для этого запроса, но 502 для следующего. Обратите внимание, что мы используем дайджест-аутентификацию с библиотекой запросов и спящей оболочкой — отсюда и шаблон 401, 200.

Чтобы еще больше усложнить отладку, проблема решается сама собой, когда Gunicorn запускается с параметром --debug. Ошибка все еще существует, если я удалю параметр --debug, но явно ограничу количество рабочих процессов Gunicorn до 1.

Мой nginx.conf:

user www-data;
worker_processes 4;
pid /var/run/nginx.pid;

events {
    worker_connections 768;
    # multi_accept on;
}

http {

    ##
    # Basic Settings
    ##

    sendfile on;
    tcp_nopush on;
    tcp_nodelay on;
    keepalive_timeout 65;
    types_hash_max_size 2048;
    # server_tokens off;

    # server_names_hash_bucket_size 64;
    # server_name_in_redirect off;

    include /etc/nginx/mime.types;
    default_type application/octet-stream;

    ##
    # Logging Settings
    ##

    access_log /var/log/nginx/access.log;
    error_log /var/log/nginx/error.log;

    ##
    # Gzip Settings
    ##

    gzip on;
    gzip_disable "msie6";

        gzip_proxied any;
        gzip_types application/x-ghi-packedschemafeatures-v1
        gzip_http_version 1.1;
        gzip_comp_level 1;
        gzip_min_length 500;

        proxy_buffering on;
        proxy_http_version 1.1;

    ##
    # Virtual Host Configs
    ##

    include /etc/nginx/conf.d/*.conf;
    include /etc/nginx/sites-enabled/*;
}

Файл виртуального хоста:

    server {
      listen 80;
      server_name pipeline.ourdomain.com;
      location / {
        rewrite ^ https://$server_name$request_uri permanent;
      }
}

server {
      listen 443;
      server_name pipeline.ourdomain.com;
      ssl on;
      ssl_protocols SSLv3 TLSv1;
      ssl_ciphers ALL:-ADH:+HIGH:+MEDIUM:-LOW:-SSLv2:-EXP;
      ssl_session_cache shared:SSL:10m;
      ssl_certificate     /etc/ssl/certs/ourdomain.com.combined.crt;
      ssl_certificate_key /etc/ssl/private/ourdomain.com.key;

      root /var/www/;
      location /static/ {
               alias /var/www/production/pipeline/public/;
      }

      location / {
             proxy_pass_header Server;
             proxy_set_header Host $http_host;
             proxy_redirect off;
             proxy_set_header X-Real-IP $remote_addr;
             proxy_set_header X-Scheme $scheme;
             proxy_set_header X-Forwarded-Protocol https;
             proxy_connect_timeout 240;
             proxy_read_timeout 280;
             proxy_pass http://localhost:8000/;
      }
      error_page 500 502 503 504 /static/50x.html;



}

Команда Гуникорна

#!/bin/bash
set -e
LOGFILE=/var/log/gunicorn/ea_pipeline.log
LOGDIR=$(dirname $LOGFILE)

SETTINGS=production_settings
# user/group to run as
USER=ubuntu
GROUP=ubuntu
DJANGO_PATH=$(dirname $(readlink -f $0))/../
cd $DJANGO_PATH
echo $(pwd)
. ../env/bin/activate
test -d $LOGDIR || mkdir -p $LOGDIR
exec ../env/bin/gunicorn_django \
     --user=$USER --group=$GROUP --log-level=debug \
     --preload \
     --workers=4 \
     --timeout=90 \
     --settings=$SETTINGS \
     --limit-request-line=8190 \
     --limit-request-field_size 0 \
     --pythonpath=$DJANGO_PATH \
     --log-file=$LOGFILE production_settings.py 2>>$LOGFILE

Образец журнала доступа:

67.134.170.194 - - [24/Aug/2012:00:28:17 +0000] "GET /api/v1/storage/ HTTP/1.1" 401 5 "-" "python-requests/0.13.8 CPython/2.7.3 Linux/3.2.0-29-generic"
67.134.170.194 - - [24/Aug/2012:00:28:18 +0000] "GET /api/v1/storage/ HTTP/1.1" 200 326 "-" "python-requests/0.13.8 CPython/2.7.3 Linux/3.2.0-29-generic"
67.134.170.194 - - [24/Aug/2012:00:28:18 +0000] "GET /api/v1/customer/?client_id=lamb_01 HTTP/1.1" 502 18 "-" "python-requests/0.13.8 CPython/2.7.3 Linux/3.2.0-29-generic"
67.134.170.194 - - [24/Aug/2012:00:29:41 +0000] "GET /api/v1/storage/ HTTP/1.1" 502 18 "-" "python-requests/0.13.8 CPython/2.7.3 Linux/3.2.0-29-generic"

Журнал ошибок Nginx:

2012/08/24 00:28:18 [error] 16490#0: *3 connect() failed (111: Connection refused) while connecting to upstream, client: 67.134.170.194, server: pipeline.ourdomain.com, request: "GET /api/v1/customer/?client_id=lamb_01 HTTP/1.1", upstream: "http://127.0.0.1:8000/api/v1/customer/?client_id=lamb_01", host: "pipeline.ourdomain.com"
2012/08/24 00:29:41 [error] 16490#0: *7 connect() failed (111: Connection refused) while connecting to upstream, client: 67.134.170.194, server: pipeline.ourdomain.com, request: "GET /api/v1/storage/ HTTP/1.1", upstream: "http://127.0.0.1:8000/api/v1/storage/", host: "pipeline.ourdomain.com"

Образец журнала Gunicorn:

2012-08-24 17:03:13 [8716] [INFO] Starting gunicorn 0.14.3
2012-08-24 17:03:13 [8716] [DEBUG] Arbiter booted
2012-08-24 17:03:13 [8716] [INFO] Listening at: http://127.0.0.1:8000 (8716)
2012-08-24 17:03:13 [8716] [INFO] Using worker: sync
2012-08-24 17:03:13 [8735] [INFO] Booting worker with pid: 8735
2012-08-24 17:03:13 [8736] [INFO] Booting worker with pid: 8736
2012-08-24 17:03:13 [8737] [INFO] Booting worker with pid: 8737
2012-08-24 17:03:13 [8738] [INFO] Booting worker with pid: 8738
2012-08-24 17:03:21 [8738] [DEBUG] GET /api/v1/storage/
Assertion failed: ok (mailbox.cpp:84)
2012-08-24 17:03:21 [8738] [INFO] Parent changed, shutting down: <Worker 8738>
2012-08-24 17:03:21 [8738] [INFO] Worker exiting (pid: 8738)
Error in sys.exitfunc:
2012-08-24 17:03:21 [8737] [DEBUG] GET /api/v1/storage/
2012-08-24 17:03:22 [8838] [INFO] Starting gunicorn 0.14.3
2012-08-24 17:03:22 [8838] [ERROR] Connection in use: ('127.0.0.1', 8000)
2012-08-24 17:03:22 [8838] [ERROR] Retrying in 1 second.
2012-08-24 17:03:22 [8737] [INFO] Parent changed, shutting down: <Worker 8737>
2012-08-24 17:03:22 [8737] [INFO] Worker exiting (pid: 8737)
Error in sys.exitfunc:
2012-08-24 17:03:22 [8736] [DEBUG] GET /api/v1/customer/
2012-08-24 17:03:23 [8736] [INFO] Parent changed, shutting down: <Worker 8736>
2012-08-24 17:03:23 [8736] [INFO] Worker exiting (pid: 8736)
Error in sys.exitfunc:
2012-08-24 17:03:23 [8838] [ERROR] Connection in use: ('127.0.0.1', 8000)
2012-08-24 17:03:23 [8838] [ERROR] Retrying in 1 second.
2012-08-24 17:03:24 [8735] [DEBUG] GET /api/v1/upload_action/
2012-08-24 17:03:24 [8838] [ERROR] Connection in use: ('127.0.0.1', 8000)
2012-08-24 17:03:24 [8838] [ERROR] Retrying in 1 second.
2012-08-24 17:03:24 [8735] [INFO] Parent changed, shutting down: <Worker 8735>
2012-08-24 17:03:24 [8735] [INFO] Worker exiting (pid: 8735)
Error in sys.exitfunc:
2012-08-24 17:03:25 [8838] [DEBUG] Arbiter booted
2012-08-24 17:03:25 [8838] [INFO] Listening at: http://127.0.0.1:8000 (8838)
2012-08-24 17:03:25 [8838] [INFO] Using worker: sync
2012-08-24 17:03:25 [8907] [INFO] Booting worker with pid: 8907
2012-08-24 17:03:25 [8908] [INFO] Booting worker with pid: 8908
2012-08-24 17:03:25 [8909] [INFO] Booting worker with pid: 8909
2012-08-24 17:03:25 [8910] [INFO] Booting worker with pid: 8910

person AndrewJesaitis    schedule 24.08.2012    source источник
comment
@VBart Nginx регистрируется в access.log   -  person AndrewJesaitis    schedule 30.08.2012
comment
Но в вашем конфиге: error_log /var/log/nginx/error.log;. Более того, формат журнала ошибок nginx другой, не тот, что вы здесь показали.   -  person VBart    schedule 30.08.2012
comment
@VBart Ты прав. Добавил выше.   -  person AndrewJesaitis    schedule 30.08.2012
comment
Хорошо, теперь совершенно ясно, что nginx не может подключиться к пушке. И эти ошибки в логе ганикорн кажутся виновниками. Возможно, вам стоит попытаться сообщить об ошибке разработчикам пушки.   -  person VBart    schedule 30.08.2012
comment
@VBart Спасибо за информацию. Я не знал, виноват ли это gunicorn или nginx. Я нахожусь в процессе настройки uWSGI, и, кажется, все работает лучше.   -  person AndrewJesaitis    schedule 30.08.2012


Ответы (1)


Это очень старый пост. Но у меня была точно такая же проблема с настройкой NGinx+Gunicorn+Flask. У меня также была ошибка 502 с тем же журналом, что и у вас, при каждом 300-м запросе или около того. Изменение типа worker-а gunicorn на асинхронный решило проблему для меня (я выбрал gthread). Надеюсь, этот ответ поможет кому-то.

Как изменить настройку: http://docs.gunicorn.org/en/stable/settings.html#worker-class

Как выбрать тип рабочего: http://docs.gunicorn.org/en/latest/design.html#choosing-a-worker-type

И вот хорошее объяснение, почему: Сколько одновременных запросов делает получить один процесс Flask?

person Si Mon    schedule 29.01.2018