☰

nginx はしばらくの間、いくつかの POST リクエストをハングさせます

tag-icon • tag-icon nginx docker wordpress docker-compose
nginx はしばらくの間、いくつかの POST リクエストをハングさせます

Ubuntu 18.08 で実行され、docker-compose として定義されている次のスタックがあります。

  1. インスタンスmariadb:10.3.20
  2. wordpress:5.3.0-php7.2インストールされたioncubeカスタムWordPressインスタンスに基づく
  3. nginx:1.13インストールさnginx-amplify-agentれたカスタムnginxインスタンスに基づく

nginx の設定:

user  nginx;
worker_processes  auto;

error_log  /var/log/nginx/error.log warn;
pid        /var/run/nginx.pid;

events {
    worker_connections  10000;
}

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

    log_format  main  '$remote_addr - $remote_user [$time_local] "$request" '
                          '$status $body_bytes_sent "$http_referer" '
                          '"$http_user_agent" "$http_x_forwarded_for"';

    log_format  main_ext  '$remote_addr - $remote_user [$time_local] "$request" '
                          '$status $body_bytes_sent "$http_referer" '
                          '"$http_user_agent" "$http_x_forwarded_for" '
                          '"$host" sn="$server_name" '
                          'rt=$request_time '
                          'ua="$upstream_addr" us="$upstream_status" '
                          'ut="$upstream_response_time" ul="$upstream_response_length" '
                          'cs=$upstream_cache_status' ;

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

    sendfile        on;
    #tcp_nopush     on;

    keepalive_timeout  65;

    gzip  on;

    include /etc/nginx/conf.d/*.conf;
}

サイトは次のように定義されます。

server {
        listen 80;
        listen [::]:80;

        server_name some.org www.some.org;

        location / {
                rewrite ^ https://$host$request_uri? permanent;
        }
}

server {
        listen 443 ssl http2;
        listen [::]:443 ssl http2;
        server_name some.org www.some.org;

        index index.php index.html index.htm;

        root /var/www/html;

        server_tokens off;

        ssl_certificate /etc/letsencrypt/live/some.org/fullchain.pem;
        ssl_certificate_key /etc/letsencrypt/live/some.org/privkey.pem;

        add_header X-Frame-Options "SAMEORIGIN" always;
        add_header X-XSS-Protection "1; mode=block" always;
        add_header X-Content-Type-Options "nosniff" always;
        add_header Referrer-Policy "no-referrer-when-downgrade" always;
        add_header Content-Security-Policy "default-src * data: 'unsafe-eval' 'unsafe-inline'" always;
        # add_header Strict-Transport-Security "max-age=31536000; includeSubDomains; preload" always;
        # enable strict transport security only if you understand the implications

        location / {
                proxy_connect_timeout 600;
                proxy_send_timeout    600;
                proxy_read_timeout    600;
                proxy_redirect        off;
                proxy_pass http://wordpress;

                proxy_set_header      X-Real-IP $remote_addr;
                proxy_set_header      X-Forwarded-Proto https;
                proxy_set_header      X-Forwarded-For $proxy_add_x_forwarded_for;
                proxy_set_header      Host $host;
        }

        location = /favicon.ico {
                log_not_found off; access_log off;
        }

        location = /robots.txt {
                log_not_found off; access_log off; allow all;
        }

        location ~* \.(css|js|gif|ico|jpeg|jpg|png)$ {
                expires max;
                log_not_found off;
        }
}

10～15 人のユーザーが Web サイトにアクセスしてアクションを実行しようとしない限り、スタック全体は期待どおりに動作します。この場合、一部のリクエストがハングし始め (通常は一部のコンポーネントに対する同じ POST リクエスト)、3～4 分後にエラーなしで解放され、ユーザーは実際にその結果を確認できます。ハングしている間、サイトは同じブラウザーからは応答しなくなります (ただし、他のブラウザーからはすべて正常です)。リクエストが解放されると、サイトは再び応答します。

ログもかなり奇妙です:

  • ハング/保留中のリクエストがサーバーに到着すると、nginx アクセス ログに表示されますが、wordpress ログには表示されません。
  • リクエストが最終的に解放されると（つまり処理されると）、nginxアクセスログとwordpressログに2回目に表示されますが、時間は異なります。

nginx アクセスログ:

62.96.39.243 - - [17/Jan/2020:10:56:41 +0000] "GET /something

78.43.40.52 - - [17/Jan/2020:10:56:41 +0000] "POST /ajax-bidsform.html?meth=post&yid=d7f9f1a1a0bf HTTP/2.0" 200 208 "https://some.org/xchange_XRP_to_SBERRUB/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_14_6) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/79.0.3945.117 Safari/537.36" "-"

78.43.40.52 - - [17/Jan/2020:10:56:41 +0000] "GET /something

ワードプレス:

134.19.130.91 - - [17/Jan/2020:10:56:40 +0000] "GET /something

78.43.40.52 - - [17/Jan/2020:10:50:07 +0000] "POST /ajax-bidsform.html?meth=post&yid=d7f9f1a1a0bf HTTP/1.0" 200 559 "https://some.org/xchange_XRP_to_SBERRUB/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_14_6) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/79.0.3945.117 Safari/537.36"

62.96.39.243 - - [17/Jan/2020:10:56:41 +0000] "GET /something

ご覧のとおり、ハングのPOST /ajax-bidsform.html...時刻は nginx ログでは 10:56 ですが、wordpress では 10:50 です。これは、クライアントがこの要求を実行した時刻とまったく同じです。私の理解では、これは、要求が実際に wordpress に渡されるまで、nginx レベルのどこかで約 6 分間スタックしていたことを意味します。ご覧のとおり、nginx の DDoS 保護ディレクティブはありません。

また、私の側からのメモ: リクエストがハングしている間、CPU または RAM の長期的なスパイクは発生しないため、ハードウェアの問題とは関係がない可能性があります。また、スクリプトのハング (つまりajax-bidsform.html) と何らかの関連があると考えていましたが、仮想ホスティング (以前は発生しなかった) からデジタル オーシャンのクラウド インスタンスに移行したときにのみ発生し始めたため、構成の問題であると考えられます。ログ内のリクエストのタイムラインも、それを証明しています。

これまで私は次のことを試みました:

  1. worker_connections10000に増加
  2. nginxインスタンス（ホストのインスタンスではない）をnet.core.somaxconn1024に増やす

しかし、問題はまだ発生しています。 アイデアやご意見があれば、ぜひお聞かせください。

答え1

nginxログでは10:56だが、wordpressでは10:50

これはWordPressが10:50にリクエストを受信し、10:56に結果をnginxに返したと解釈できます。確実に知るには、nginxにupstream_response_timeを追加してください。log_formatアプリケーションパフォーマンス監視に NGINX ログを使用する。

関連情報