nginx proxy_pass renvoie finalement GATEWAY_TIMEOUT même si le serveur est toujours actif

9

J'ai mis en place un passthrough de proxy nginx qui fonctionne bien lorsque nginx se charge initialement, mais finalement (peut-être après un jour ou deux?, Pas trop sûr à ce stade) l'emplacement qui est un passthrough de proxy ne renvoie qu'une 504 GATEWAY_TIMEOUTréponse. La chose étrange est que j'ai configuré plusieurs emplacements proxy_pass et c'est aléatoire ce qui descend et ce qui reste.

Voici le fichier de configuration nginx:

server {
  listen   80;
  server_name  example.com;
  access_log  /var/log/nginx/access.log;
  error_log  /var/log/nginx/error.log;
  root   /srv/www/frontend/current/;

  location / {
    try_files $uri $uri/ /index.html;
  }

  # Block all svn access
  if ($request_uri ~* ^.*\.svn.*$) {
     return 404;
  }

  # Block all git access
  if ($request_uri ~* ^.*\.git.*$) {
     return 404;
  }

  location /nginx_status {
    stub_status on;
    access_log off;
    allow 127.0.0.1;
    deny all;
  }

  location /api/karma/ {
    proxy_pass <server A>;
  }

  location /api/auth/ {
    proxy_pass <server B>;
  }

  location /api/search/ {
    proxy_pass <server C>;
  }

  location /api/history/ {
    proxy_pass <server D>;
  }
}

(J'ai anonymisé les emplacements des serveurs évidemment)

Ainsi, par exemple, lorsque nginx démarre initialement, je peux faire

curl -i example.com/api/history/health_check

(où health_check est un point final connu) et obtenez une réponse de 200, mais après un certain temps, la même commande exacte renvoie 504 GATEWAY_TIMEOUT.

Le serveur sous-jacent et le serveur http sont toujours pleinement opérationnels et je peux faire des commandes curl directement contre l'adresse du serveur et obtenir des réponses à la fois de ma machine locale et quand elles sont transférées sur le serveur nginx.

Le préfixe d'emplacement qui commence à renvoyer un GATEWAY_TIMEOUT est aléatoire, et depuis qu'il a été configuré, chacun des quatre emplacements qui ont proxy_pass ont échoué de cette façon à un moment ou à un autre.

Tout est hébergé sur des instances Linux AWS t2_micro Ubuntu 14.04 et nginx lui-même est v1.4.6. Les serveurs / applications sous-jacents ne sont pas redémarrés et les instances AWS elles-mêmes ont également fonctionné tout le temps. Les serveurs http sous-jacents sont des applications Go, mais encore une fois, lorsque je commence à obtenir ces GATEWAY_TIMEOUT, les applications elles-mêmes sont pleinement opérationnelles.

Il n'y avait rien d'intéressant dans les journaux d'erreurs lorsque cela se produit, mais je viens d'activer la journalisation du débogage sur le journal des erreurs, et voici ce qui se présente pour une demande rompue:

2015/07/13 19:56:31 [debug] 3523#0: *12096 post event 00000000022542A0
2015/07/13 19:56:31 [debug] 3523#0: *12096 delete posted event 00000000022542A0
2015/07/13 19:56:31 [debug] 3523#0: *12096 http wait request handler
2015/07/13 19:56:31 [debug] 3523#0: *12096 posix_memalign: 000000000222F6A0:256 @16
2015/07/13 19:56:31 [debug] 3523#0: *12096 malloc: 0000000002225CA0:1024
2015/07/13 19:56:31 [debug] 3523#0: *12096 recv: fd:23 1018 of 1024
2015/07/13 19:56:31 [debug] 3523#0: *12096 reusable connection: 0
2015/07/13 19:56:31 [debug] 3523#0: *12096 posix_memalign: 00000000022260B0:4096 @16
2015/07/13 19:56:31 [debug] 3523#0: *12096 http process request line
2015/07/13 19:56:31 [debug] 3523#0: *12096 http request line: "POST <url> HTTP/1.1"
2015/07/13 19:56:31 [debug] 3523#0: *12096 http uri: "<url>"
2015/07/13 19:56:31 [debug] 3523#0: *12096 http args: ""
2015/07/13 19:56:31 [debug] 3523#0: *12096 http exten: ""
2015/07/13 19:56:31 [debug] 3523#0: *12096 http process request header line
2015/07/13 19:56:31 [debug] 3523#0: *12096 http header: "host: <url>"
2015/07/13 19:56:31 [debug] 3523#0: *12096 http header: "Accept: application/json, text/plain, */*"
2015/07/13 19:56:31 [debug] 3523#0: *12096 http header: "Accept-Encoding: gzip, deflate"
2015/07/13 19:56:31 [debug] 3523#0: *12096 http header: "Accept-Language: en-US,en;q=0.8"
2015/07/13 19:56:31 [debug] 3523#0: *12096 http header: "Authorization: <auth token>"
2015/07/13 19:56:31 [debug] 3523#0: *12096 http header: "Content-Type: application/json;charset=UTF-8"
2015/07/13 19:56:31 [debug] 3523#0: *12096 http header: "Origin: <url>"
2015/07/13 19:56:31 [debug] 3523#0: *12096 http header: "Referer: <url>"
2015/07/13 19:56:31 [debug] 3523#0: *12096 http header: "User-Agent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_10_4) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/43.0.2357.132 Safari/537.36"
2015/07/13 19:56:31 [debug] 3523#0: *12096 http header: "X-Forwarded-For: <ip address>"
2015/07/13 19:56:31 [debug] 3523#0: *12096 http header: "X-Forwarded-Port: 443"
2015/07/13 19:56:31 [debug] 3523#0: *12096 http header: "X-Forwarded-Proto: https"
2015/07/13 19:56:31 [debug] 3523#0: *12096 http header: "Content-Length: 209"
2015/07/13 19:56:31 [debug] 3523#0: *12096 posix_memalign: 00000000022270C0:4096 @16
2015/07/13 19:56:31 [debug] 3523#0: *12096 http header: "Connection: keep-alive"
2015/07/13 19:56:31 [debug] 3523#0: *12096 http header done
2015/07/13 19:56:31 [debug] 3523#0: *12096 event timer del: 23: 1436817428740
2015/07/13 19:56:31 [debug] 3523#0: *12096 generic phase: 0
2015/07/13 19:56:31 [debug] 3523#0: *12096 rewrite phase: 1

** snip ( bunch of logs about trying to match the url to a route )

2015/07/13 19:56:31 [debug] 3523#0: *12096 http cl:209 max:4194304
2015/07/13 19:56:31 [debug] 3523#0: *12096 rewrite phase: 3
2015/07/13 19:56:31 [debug] 3523#0: *12096 post rewrite phase: 4
2015/07/13 19:56:31 [debug] 3523#0: *12096 generic phase: 5
2015/07/13 19:56:31 [debug] 3523#0: *12096 generic phase: 6
2015/07/13 19:56:31 [debug] 3523#0: *12096 generic phase: 7
2015/07/13 19:56:31 [debug] 3523#0: *12096 access phase: 8
2015/07/13 19:56:31 [debug] 3523#0: *12096 access phase: 9
2015/07/13 19:56:31 [debug] 3523#0: *12096 post access phase: 10
2015/07/13 19:56:31 [debug] 3523#0: *12096 try files phase: 11
2015/07/13 19:56:31 [debug] 3523#0: *12096 http client request body preread 209
2015/07/13 19:56:31 [debug] 3523#0: *12096 http request body content length filter
2015/07/13 19:56:31 [debug] 3523#0: *12096 http body new buf t:1 f:0 0000000002225FC9, pos 0000000002225FC9, size: 209 file: 0, size: 0
2015/07/13 19:56:31 [debug] 3523#0: *12096 http init upstream, client timer: 0
2015/07/13 19:56:31 [debug] 3523#0: *12096 epoll add event: fd:23 op:3 ev:80000005
2015/07/13 19:56:31 [debug] 3523#0: *12096 http script copy: "Host: "
2015/07/13 19:56:31 [debug] 3523#0: *12096 http script var: "<aws url>"
2015/07/13 19:56:31 [debug] 3523#0: *12096 http script copy: "
"
2015/07/13 19:56:31 [debug] 3523#0: *12096 http script copy: "Connection: close
"
2015/07/13 19:56:31 [debug] 3523#0: *12096 http script copy: "Content-Length: "
2015/07/13 19:56:31 [debug] 3523#0: *12096 http script var: "209"
2015/07/13 19:56:31 [debug] 3523#0: *12096 http script copy: "
"
2015/07/13 19:56:31 [debug] 3523#0: *12096 http proxy header: "Accept: application/json, text/plain, */*"
2015/07/13 19:56:31 [debug] 3523#0: *12096 http proxy header: "Accept-Encoding: gzip, deflate"
2015/07/13 19:56:31 [debug] 3523#0: *12096 http proxy header: "Accept-Language: en-US,en;q=0.8"
2015/07/13 19:56:31 [debug] 3523#0: *12096 http proxy header: "Authorization: <auth>"
2015/07/13 19:56:31 [debug] 3523#0: *12096 http proxy header: "Content-Type: application/json;charset=UTF-8"
2015/07/13 19:56:31 [debug] 3523#0: *12096 http proxy header: "Origin: <url>"
2015/07/13 19:56:31 [debug] 3523#0: *12096 http proxy header: "Referer: <url>"
2015/07/13 19:56:31 [debug] 3523#0: *12096 http proxy header: "User-Agent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_10_4) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/43.0.2357.132 Safari/537.36"
2015/07/13 19:56:31 [debug] 3523#0: *12096 http proxy header: "X-Forwarded-For: 96.45.202.230"
2015/07/13 19:56:31 [debug] 3523#0: *12096 http proxy header: "X-Forwarded-Port: 443"
2015/07/13 19:56:31 [debug] 3523#0: *12096 http proxy header: "X-Forwarded-Proto: https"
2015/07/13 19:56:31 [debug] 3523#0: *12096 http proxy header:
"POST /v1/trip HTTP/1.0
Host: <url>
Connection: close
Content-Length: 209
Accept: application/json, text/plain, */*
Accept-Encoding: gzip, deflate
Accept-Language: en-US,en;q=0.8
Authorization: <auth>
Content-Type: application/json;charset=UTF-8
Origin: <url>
Referer: <url>
User-Agent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_10_4) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/43.0.2357.132 Safari/537.36
X-Forwarded-For: 96.45.202.230
X-Forwarded-Port: 443
X-Forwarded-Proto: https

"
2015/07/13 19:56:31 [debug] 3523#0: *12096 http cleanup add: 0000000002227C40
2015/07/13 19:56:31 [debug] 3523#0: *12096 get rr peer, try: 2
2015/07/13 19:56:31 [debug] 3523#0: *12096 get rr peer, current: 1 0
2015/07/13 19:56:31 [debug] 3523#0: *12096 socket 24
2015/07/13 19:56:31 [debug] 3523#0: *12096 epoll add connection: fd:24 ev:80000005
2015/07/13 19:56:31 [debug] 3523#0: *12096 connect to 54.174.36.245:80, fd:24 #12097
2015/07/13 19:56:31 [debug] 3523#0: *12096 http upstream connect: -2
2015/07/13 19:56:31 [debug] 3523#0: *12096 posix_memalign: 000000000222F7B0:128 @16
2015/07/13 19:56:31 [debug] 3523#0: *12096 event timer add: 24: 60000:1436817451902
2015/07/13 19:56:31 [debug] 3523#0: *12096 http finalize request: -4, "<url>" a:1, c:2
2015/07/13 19:56:31 [debug] 3523#0: *12096 http request count:2 blk:0
2015/07/13 19:56:31 [debug] 3523#0: *12096 post event 000000000226E2B0
2015/07/13 19:56:31 [debug] 3523#0: *12096 delete posted event 000000000226E2B0
2015/07/13 19:56:31 [debug] 3523#0: *12096 http run request: "<url>"
2015/07/13 19:56:31 [debug] 3523#0: *12096 http upstream check client, write event:1, "<url>"
2015/07/13 19:56:31 [debug] 3523#0: *12096 http upstream recv(): -1 (11: Resource temporarily unavailable)
2015/07/13 19:56:31 [debug] 3523#0: post event 0000000002253E90
2015/07/13 19:56:31 [debug] 3523#0: delete posted event 0000000002253E90
2015/07/13 19:56:31 [debug] 3523#0: accept on 0.0.0.0:80, ready: 0
2015/07/13 19:56:31 [debug] 3523#0: posix_memalign: 000000000222F840:256 @16
2015/07/13 19:56:31 [debug] 3523#0: *12098 accept: 172.31.15.160 fd:25
2015/07/13 19:56:31 [debug] 3523#0: *12098 event timer add: 25: 60000:1436817451902
2015/07/13 19:56:31 [debug] 3523#0: *12098 reusable connection: 1
2015/07/13 19:56:31 [debug] 3523#0: *12098 epoll add event: fd:25 op:1 ev:80000001
2015/07/13 19:56:31 [debug] 3523#0: post event 0000000002253E90
2015/07/13 19:56:31 [debug] 3523#0: delete posted event 0000000002253E90
2015/07/13 19:56:31 [debug] 3523#0: accept on 0.0.0.0:80, ready: 0
2015/07/13 19:56:31 [debug] 3523#0: posix_memalign: 000000000222F950:256 @16
2015/07/13 19:56:31 [debug] 3523#0: *12099 accept: 172.31.15.160 fd:26
2015/07/13 19:56:31 [debug] 3523#0: *12099 event timer add: 26: 60000:1436817451902
2015/07/13 19:56:31 [debug] 3523#0: *12099 reusable connection: 1
2015/07/13 19:56:31 [debug] 3523#0: *12099 epoll add event: fd:26 op:1 ev:80000001
2015/07/13 19:56:31 [debug] 3523#0: *12096 post event 000000000226E040
2015/07/13 19:56:31 [debug] 3523#0: *12096 delete posted event 000000000226E040
2015/07/13 19:56:31 [debug] 3523#0: *12096 http upstream request: "<url>"
2015/07/13 19:56:31 [debug] 3523#0: *12096 http upstream send request handler
2015/07/13 19:56:31 [debug] 3523#0: *12096 http upstream send request
2015/07/13 19:56:31 [debug] 3523#0: *12096 chain writer buf fl:0 s:830
2015/07/13 19:56:31 [debug] 3523#0: *12096 chain writer buf fl:1 s:209
2015/07/13 19:56:31 [debug] 3523#0: *12096 chain writer in: 0000000002227C98
2015/07/13 19:56:31 [debug] 3523#0: *12096 writev: 1039
2015/07/13 19:56:31 [debug] 3523#0: *12096 chain writer out: 0000000000000000
2015/07/13 19:56:31 [debug] 3523#0: *12096 event timer del: 24: 1436817451902
2015/07/13 19:56:31 [debug] 3523#0: *12096 event timer add: 24: 60000:1436817451904
2015/07/13 19:56:31 [debug] 3523#0: *12096 post event 0000000002254030
2015/07/13 19:56:31 [debug] 3523#0: *12096 post event 000000000226E040
2015/07/13 19:56:31 [debug] 3523#0: *12096 delete posted event 000000000226E040
2015/07/13 19:56:31 [debug] 3523#0: *12096 http upstream request: "<url>"
2015/07/13 19:56:31 [debug] 3523#0: *12096 http upstream dummy handler
2015/07/13 19:56:31 [debug] 3523#0: *12096 delete posted event 0000000002254030
2015/07/13 19:56:31 [debug] 3523#0: *12096 http upstream request: "<url>"
2015/07/13 19:56:31 [debug] 3523#0: *12096 http upstream process header
2015/07/13 19:56:31 [debug] 3523#0: *12096 malloc: 00000000022280D0:4096
2015/07/13 19:56:31 [debug] 3523#0: *12096 recv: fd:24 141 of 4096
2015/07/13 19:56:31 [debug] 3523#0: *12096 http proxy status 200 "200 OK"
2015/07/13 19:56:31 [debug] 3523#0: *12096 http proxy header: "Content-Type: text/plain"
2015/07/13 19:56:31 [debug] 3523#0: *12096 http proxy header: "Date: Mon, 13 Jul 2015 19:56:31 GMT"
2015/07/13 19:56:31 [debug] 3523#0: *12096 http proxy header: "Server: nginx/1.6.2"
2015/07/13 19:56:31 [debug] 3523#0: *12096 http proxy header: "Content-Length: 0"
2015/07/13 19:56:31 [debug] 3523#0: *12096 http proxy header: "Connection: Close"
2015/07/13 19:56:31 [debug] 3523#0: *12096 http proxy header done
2015/07/13 19:56:31 [debug] 3523#0: *12096 xslt filter header
2015/07/13 19:56:31 [debug] 3523#0: *12096 HTTP/1.1 200 OK
Server: nginx/1.4.6 (Ubuntu)
Date: Mon, 13 Jul 2015 19:56:31 GMT
Content-Type: text/plain
Content-Length: 0
Connection: keep-alive

La ligne intéressante (pour moi) est:

2015/07/13 19:56:31 [debug] 3523#0: *12096 http upstream recv(): -1 (11: Resource temporarily unavailable)

J'ai essayé de rechercher cette chaîne dans Google, mais pour être honnête, je ne comprends pas vraiment les réponses et elles ne semblent pas liées au problème que j'ai.

syazdani
la source
nginx utilise des E / S non bloquantes. Cette erreur à laquelle vous faites référence est parfaitement normale, elle indique simplement à nginx que rien ne peut être lu à partir de cette prise en ce moment.
Oliver

Réponses:

1

Le goulot d'étranglement est probablement dans votre nombre t2_micro de descripteurs de fichiers, mais il est également très probable qu'il s'agisse d'un problème de bande passante réseau.

Il existe deux façons génériques de résoudre ce problème sans augmenter la bande passante: 1) Augmenter la limite (nombre) de fichiers ouverts à l'échelle du système et / ou ulimit pour nginx 2) Mettre à niveau vers nginx 1.7.5 ou supérieur

Si l'augmentation des descripteurs de fichiers ne résout pas le problème, gardez à l'esprit que le t2_micro est généralement un produit à faible bande passante réseau. Bien que vous ne puissiez pas obtenir de «meilleures» performances réseau, vous pouvez essayer une réponse proxy plus précise health_check qui minimise les faiblesses de t2_micro, en utilisant quelques ajustements:

  • La mise en mémoire tampon est activée par défaut, alors vérifiez que le chemin par défaut spécifié dans proxy_temp_pathexiste et dispose d'un espace disque suffisant, car si ce n'est pas le cas, les messages mis en mémoire tampon peuvent être sporadiquement vides ou manqués et créer une condition de délai d'attente en attendant la réponse.
  • Vous aurez besoin de la version 1.7.5 ou supérieure pour ajuster proxy_next_upstream_timeoutet proxy_next_upstream_triespour que nginx gère les demandes de proxy «plus intelligemment» sur un serveur à faible bande passante. Par exemple, vous pouvez définir un certain nombre de tentatives avant de transmettre une erreur.

MISE À JOUR: Pour configurer le nombre d'essais de proxy avant une erreur dans la version 1.7.5 et supérieure, ajoutez cette entrée à nginx.conf:

proxy_next_upstream_tries 3;

Cela vous donnera deux tentatives (un essai, plus deux tentatives).

Andrew S
la source
Cool! Je vais essayer la deuxième option (mise à niveau vers la dernière version stable de nginx) et voir ce qui se passe. Généralement, cela prend un ou deux jours avant que le problème ne se déclenche, donc je posterai une réponse ici après sur les résultats.
syazdani
Impressionnant. La mise à niveau vers 1.7.5 en elle-même ne résoudra probablement pas le problème. Puisque le proxy_retries par défaut est 0, vous devrez éditer nginx.conf et ajouter le paramètre avec un nombre comme 1 ou 2. Le pouce vers le haut aide, mais laissez toujours OP savoir ce que vous avez fait pour résoudre finalement le problème.
Andrew S
J'ai mis à jour ma réponse avec le format de l'option proxy_next_upsteam_tries
Andrew S
Je viens donc de passer à nginx 1.8.0 et cela fait environ une semaine que nous n'avons eu aucun problème. Cela ne signifie pas que son 100% disparu, mais assez bon pour moi en ce moment.
syazdani
1

Ajoutez ceci à nginx.conf:

proxy_connect_timeout 600;
proxy_send_timeout 600;
proxy_read_timeout 600;
send_timeout 600;

Ensuite, faites «service nginx reload» («systemctl nginx reload» si vous utilisez systemd)

Sean1e
la source