Nginx proxy_read_timeout contre proxy_connect_timeout

J'ai commencé à utiliser Nginx comme proxy inverse pour un ensemble de serveurs qui fournissent une sorte de service.

Le service peut parfois être assez lent (son fonctionnement sur Java et la JVM est parfois coincé dans une "récupération de place complète" qui peut prendre plusieurs secondes), j'ai donc défini la valeur proxy_connect_timeoutà 2 secondes, ce qui donnera à Nginx suffisamment de temps pour comprendre que le service est bloqué sur GC et ne répondra pas à temps, et il doit transmettre la demande à un autre serveur.

J'ai également décidé proxy_read_timeoutd'empêcher le proxy inverse de se bloquer si le service lui-même prend trop de temps pour calculer la réponse - encore une fois, il devrait déplacer la demande vers un autre serveur qui devrait être suffisamment libre pour renvoyer une réponse en temps opportun.

J'ai exécuté des tests de performance et je peux voir clairement que cela proxy_connect_timeoutfonctionne correctement car certaines demandes retournent exactement à l'heure spécifiée pour le délai de connexion, car le service est bloqué et n'accepte pas les connexions entrantes (le service utilise Jetty comme un embarqué conteneur de servlet). Le proxy_read_timeoutfonctionne également, comme je peux voir que les demandes de retour après le délai spécifié il.

Le problème est que je m'attendais à voir certaines demandes qui expirent après proxy_read_timeout + proxy_connect_timeout, ou presque cette durée, si le service est bloqué et n'accepte pas les connexions lorsque Nginx essaie d'y accéder, mais avant que Nginx ne puisse expirer - il est libéré et commence le traitement, mais est trop lent et Nginx serait abandonné en raison du délai de lecture. Je crois que le service a de tels cas, mais après avoir exécuté plusieurs tests de référence, totalisant plusieurs millions de demandes - je n'ai pas vu une seule demande qui retourne dans quoi que ce soit ci-dessus proxy_read_timeout(qui est le plus grand délai d'attente).

J'apprécierais tout commentaire sur ce problème, bien que je pense que cela pourrait être dû à un bogue dans Nginx (je n'ai pas encore examiné le code, donc ce n'est qu'une hypothèse) que le compteur de délai d'attente n'est pas réinitialisé après la connexion est réussie, si Nginx n'a rien lu du serveur en amont.

Je n'ai en fait pas pu reproduire ceci sur:

2011/08/20 20:08:43 [notice] 8925#0: nginx/0.8.53
2011/08/20 20:08:43 [notice] 8925#0: built by gcc 4.1.2 20080704 (Red Hat 4.1.2-48)
2011/08/20 20:08:43 [notice] 8925#0: OS: Linux 2.6.39.1-x86_64-linode19

J'ai mis cela en place dans mon nginx.conf:

proxy_connect_timeout   10;
proxy_send_timeout      15;
proxy_read_timeout      20;

J'ai ensuite installé deux serveurs de test. Un qui expirerait simplement sur le SYN et un qui accepterait les connexions mais ne répondrait jamais:

upstream dev_edge {
  server 127.0.0.1:2280 max_fails=0 fail_timeout=0s; # SYN timeout
  server 10.4.1.1:22 max_fails=0 fail_timeout=0s; # accept but never responds
}

Ensuite, j'ai envoyé une connexion de test:

[m4@ben conf]$ telnet localhost 2480
Trying 127.0.0.1...
Connected to localhost.
Escape character is '^]'.
GET / HTTP/1.1
Host: localhost

HTTP/1.1 504 Gateway Time-out
Server: nginx
Date: Sun, 21 Aug 2011 03:12:03 GMT
Content-Type: text/html
Content-Length: 176
Connection: keep-alive

Puis regardé error_log qui a montré ceci:

2011/08/20 20:11:43 [error] 8927#0: *1 upstream timed out (110: Connection timed out) while connecting to upstream, client: 127.0.0.1, server: ben.dev.b0.lt, request: "GET / HTTP/1.1", upstream: "http://10.4.1.1:22/", host: "localhost"

ensuite:

2011/08/20 20:12:03 [error] 8927#0: *1 upstream timed out (110: Connection timed out) while reading response header from upstream, client: 127.0.0.1, server: ben.dev.b0.lt, request: "GET / HTTP/1.1", upstream: "http://127.0.0.1:2280/", host: "localhost"

Et puis le fichier access.log qui a le délai d'attente 30s prévu (10 + 20):

504:32.931:10.003, 20.008:.:176 1 127.0.0.1 localrhost - [20/Aug/2011:20:12:03 -0700] "GET / HTTP/1.1" "-" "-" "-" dev_edge 10.4.1.1:22, 127.0.0.1:2280 -

Voici le format de journal que j'utilise, qui inclut les délais d'attente individuels en amont:

log_format  edge  '$status:$request_time:$upstream_response_time:$pipe:$body_bytes_sent $connection $remote_addr $host $remote_user [$time_local] "$request" "$http_referer" "$http_user_agent" "$http_x_forwarded_for" $edge $upstream_addr $upstream_cache_status';

Le problème est que je m'attendais à voir certaines demandes expirer après proxy_read_timeout + proxy_connect_timeout, ou presque cette durée, si le service est bloqué et n'accepte pas les connexions lorsque Nginx essaie d'y accéder, mais avant que Nginx ne puisse expirer - il est libéré et commence le traitement, mais est trop lent et Nginx abandonnerait en raison du délai de lecture.

Le délai d'expiration de la connexion signifie que TCP se bloque lors de l'établissement d'une liaison (par exemple, il n'y avait pas de SYN_ACK). TCP essaierait à nouveau d'envoyer des SYN, mais vous n'avez donné que 2 secondes. à Nginx pour utiliser un autre serveur, il n'a donc tout simplement pas le temps de renvoyer des SYN.

UPD. : Impossible de trouver dans les documents, mais tcpdump montre qu'il y a 3 secondes. délai entre le 1er SYN envoyé et la 2e tentative d'envoi du SYN.