strange behaviour with ip_hash (client redirected to different nodes from upstream)

rsawer nginx-forum at nginx.us
Fri Dec 3 18:45:51 MSK 2010 

Today while debugging a strange issue with our PHP application, we have
discovered, that some requests from client's ip were propagated to
different nodes from an upstream clausule, inspite of using ip_hash
algorithm


Below is the upstream clasule:

upstream pula_partnerzy20 {
ip_hash;
server 12.0.0.31:90 max_fails=2 fail_timeout=10m down;
server 12.0.0.32:90 max_fails=2 fail_timeout=10m;
server 12.0.0.33:90 max_fails=2 fail_timeout=10m;
}



Vhost configuration below:

server {
    listen       99;
    server_name  domain.org;


    location / {
        proxy_set_header Host $http_host;
        proxy_set_header X-Forwarded-For $proxy_add_x_forwarded_for;


        if ($request_method = POST ) {
	        proxy_pass http://pula_partnerzy20;
        	break;
        }

        set $memc_cmd 'get';
        set $memc_key $request_uri;
        memc_pass memcache;
        memc_flags_to_last_modified on;
        error_page 404 502 504 500 = /fallback;
    }

    error_page   500 502 503 504  /50x.html;

    location = /50x.html {
        root   html;
    }

    location = /fallback {
        internal;
        proxy_set_header Host $http_host;
        proxy_set_header X-Forwarded-For $proxy_add_x_forwarded_for;
        proxy_pass http://pula_partnerzy20;
    }

}

Notice: inspite of sending calls to memcache in the vhost config, our
memcache has been turned off some time ago, so there are the 502's in
the access log

Here is the access log (with hoaxed client IP):

89.215.266.49 domain.org "02/Dec/2010:21:11:41 +0100" "127.0.0.1:11212,
memcache : 12.0.0.33:90" "GET /dbr/images/dot_external.gif?c=fac52b5f
HTTP/1.1" 200 (502, 502 : 200) UP_RESPONSE 0.000, 0.000 : 0.001
request_time 0.001
89.215.266.49 domain.org "02/Dec/2010:21:11:41 +0100" "127.0.0.1:11212,
memcache : 12.0.0.33:90" "GET /dbr/images/paging-bottom.gif?c=ce034e2f
HTTP/1.1" 200 (502, 502 : 200) UP_RESPONSE 0.000, 0.000 : 0.001
request_time 0.001
89.215.266.49 domain.org "02/Dec/2010:21:11:41 +0100" "127.0.0.1:11212,
memcache : 12.0.0.33:90" "GET /dbr/images/ico-world.gif?c=67011679
HTTP/1.1" 200 (502, 502 : 200) UP_RESPONSE 0.000, 0.000 : 0.002
request_time 0.002
89.215.266.49 domain.org "02/Dec/2010:21:11:41 +0100" "127.0.0.1:11212,
memcache : 12.0.0.33:90" "GET /dbr/images/dings-top.gif?c=6b47dd44
HTTP/1.1" 200 (502, 502 : 200) UP_RESPONSE 0.000, 0.000 : 0.013
request_time 0.013
89.215.266.49 domain.org "02/Dec/2010:21:11:42 +0100" "127.0.0.1:11212,
memcache : 12.0.0.33:90" "GET /dbr/images/ico-date.gif?c=126a1a8a
HTTP/1.1" 200 (502, 502 : 200) UP_RESPONSE 0.000, 0.000 : 0.001
request_time 0.001
89.215.266.49 domain.org "02/Dec/2010:21:12:33 +0100" "127.0.0.1:11212,
memcache : 12.0.0.33:90" "GET /dbr/images/ajax-loader.gif?c=ed0e5384
HTTP/1.1" 200 (502, 502 : 200) UP_RESPONSE 0.000, 0.000 : 0.003
request_time 0.003
89.215.266.49 domain.org "02/Dec/2010:21:12:33 +0100" "127.0.0.1:11212,
memcache : 12.0.0.32:90" "GET
/flights/select/0/0//4/1/BTSIbj0RsDHl1S-27Fllkl6GAbOTWOht0ubLlQ0Kx-s?format=html
HTTP/1.1" 200 (502, 502 : 200) UP_RESPONSE 0.000, 0.000 : 0.089
request_time 0.089
89.215.266.49 domain.org "02/Dec/2010:21:13:17 +0100" "127.0.0.1:11212,
memcache : 12.0.0.32:90" "GET
/flights/select/2010-12-15/2011-01-04//asc/1/BTSIbj0RsDHl1S-27Fllkl6GAbOTWOht0ubLlQ0Kx-s//format/html
HTTP/1.1" 302 (502, 502 : 302) UP_RESPONSE 0.000, 0.000 : 0.309
request_time 0.309
89.215.266.49 domain.org "02/Dec/2010:21:13:17 +0100" "127.0.0.1:11212,
memcache : 12.0.0.32:90" "GET /flights/searching/msg/search?R= HTTP/1.1"
200 (502, 502 : 200) UP_RESPONSE 0.000, 0.000 : 0.135 request_time
0.135
89.215.266.49 domain.org "02/Dec/2010:21:13:31 +0100" "127.0.0.1:11212,
memcache : 12.0.0.32:90" "GET
/flights/searching2/R/BTSIbj0RsDHl1S-27Fllkl6GAbOTWOht0ubLlQ0Kx-s
HTTP/1.1" 200 (502, 502 : 200) UP_RESPONSE 0.000, 0.000 : 12.115
request_time 12.115
89.215.266.49 domain.org "02/Dec/2010:21:13:31 +0100" "127.0.0.1:11212,
memcache : 12.0.0.32:90" "GET
/flights/select/0/0//asc/0/BTSIbj0RsDHl1S-27Fllkl6GAbOTWOht0ubLlQ0Kx-s
HTTP/1.1" 200 (502, 502 : 200) UP_RESPONSE 0.000, 0.000 : 0.259
request_time 0.259
89.215.266.49 domain.org "02/Dec/2010:21:13:31 +0100" "127.0.0.1:11212,
memcache : 12.0.0.32:90" "GET
/packed/flights_i18n-bg-f96c0114.js?c=9f909277 HTTP/1.1" 200 (502, 502 :
200) UP_RESPONSE 0.000, 0.000 : 0.005 request_time 0.005


As you can see, client's IP address has been computed by ip_hash to use
12.0.0.33 server backend. Everything is OK until suddenly client is
directed to 12.0.0.32 backend.
I've done greping (for 500 status codes which could mark upstream),
searching error log for some clues and nothing. What also wonders me is
there there is nothing like "12.0.0.33, 12.0.0.32 : 12.0.0.32" in
$upstream_addr in the log above, it looks like ip_hash has just computed
other value than usual

Can anyone help me solving this issue?

I'm using:
nginx version: nginx/0.7.67
built by gcc 4.3.2 (Debian 4.3.2-1.1)
TLS SNI support enabled
configure arguments: --with-http_stub_status_module
--prefix=/usr/local/nginx/ --with-openssl=/root/openssl-0.9.8p
--add-module=/root/agentzh-memc-nginx-module-b2aeae2/ --with-debug
--add-module=/root/agentzh-headers-more-nginx-module-9508330/
--with-http_ssl_module --with-openssl-opt=enable-tlsext

Posted at Nginx Forum: http://forum.nginx.org/read.php?2,155313,155313#msg-155313

More information about the nginx mailing list