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