We have the following setup: Nginx -> Varnish -> HAProxy -> App Server A / App Server B.
Most request we process are proxied by HAProxy to App Server A. This is done based on host header values. A few hosts should be redirected to App Server B. Traffic to App Server B is very low.
Most request work fine. Every once in a while requests that should be proxied to App Server B give a 404 Status Code. These requests show up in logs of Nginx, Varnish, and App Server A, but not HAProxy.
Requests to App Server A and B that work fine are properly logged by HAProxy.
It seems that Varnish reuses connections to App Server A established by HAProxy, preventing those requests from being reevaluated and sent to the proper backend. Is this a plausible cause of my problems? Is there a way to force Varnish to reconnect to the backend, or HAProxy to remain in between these servers? What are advantages / disadvantages of each solution?
Thanks!
Edit:
This is the part from my Varnish log file:
12 SessionClose c Connection: close
12 StatSess c 127.0.0.1 54331 0 1 1 0 0 1 652 0
0 CLI - Rd ping
0 CLI - Wr 200 PONG 1329319173 1.0
12 SessionOpen c 127.0.0.1 54334 :6081
12 ReqStart c 127.0.0.1 54334 1884874126
12 RxRequest c GET
12 RxURL c /path/to/page
12 RxProtocol c HTTP/1.0
12 RxHeader c Host: www.example.com
12 RxHeader c Connection: close
12 RxHeader c User-Agent: Mozilla/5.0 (Windows NT 6.1; WOW64) AppleWebKit/535.7 (KHTML, like Gecko) Chrome/16.0.912.77 Safari/535.7
12 RxHeader c Accept: text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8
12 RxHeader c Referer: http://www.example.com/path/to/previous/
12 RxHeader c Accept-Encoding: gzip,deflate,sdch
12 RxHeader c Accept-Language: en-US,en;q=0.8
12 RxHeader c Accept-Charset: ISO-8859-1,utf-8;q=0.7,*;q=0.3
12 RxHeader c Cookie: 71666-bl0098f964_r=0; 71666-bl0098f964_s=145818062; _advocaten-cms_session=BAh7BjoPc2Vzc2lvbl9pZCIlMmRhNGFhMWY3MDRlMzljNGRkZTQ0MTI3MjJhN2E2NzY%3D--5d089ff2c72e4ad91d415cb14020834387c2077e; 71666-bl0098f964_i=272; 71666-bl0098f964_vt=1329319215438
12 VCL_call c recv
12 VCL_return c pass
12 VCL_call c hash
12 VCL_return c hash
12 VCL_call c pass
12 VCL_return c pass
12 Backend c 14 default default
14 TxRequest b GET
14 TxURL b /path/to/page/
14 TxProtocol b HTTP/1.0
14 TxHeader b Host: www.example.com
14 TxHeader b User-Agent: Mozilla/5.0 (Windows NT 6.1; WOW64) AppleWebKit/535.7 (KHTML, like Gecko) Chrome/16.0.912.77 Safari/535.7
14 TxHeader b Accept: text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8
14 TxHeader b Referer: http://www.example.com/path/to/previous/
14 TxHeader b Accept-Encoding: gzip,deflate,sdch
14 TxHeader b Accept-Language: en-US,en;q=0.8
14 TxHeader b Accept-Charset: ISO-8859-1,utf-8;q=0.7,*;q=0.3
14 TxHeader b Cookie: 71666-bl0098f964_r=0; 71666-bl0098f964_s=145818062; _advocaten-cms_session=BAh7BjoPc2Vzc2lvbl9pZCIlMmRhNGFhMWY3MDRlMzljNGRkZTQ0MTI3MjJhN2E2NzY%3D--5d089ff2c72e4ad91d415cb14020834387c2077e; 71666-bl0098f964_i=272; 71666-bl0098f964_vt=1329319215438
14 TxHeader b X-Forwarded-For: 127.0.0.1
14 TxHeader b X-Varnish: 1884874126
14 RxProtocol b HTTP/1.1
14 RxStatus b 404
14 RxResponse b Not Found
14 RxHeader b Date: Wed, 15 Feb 2012 15:20:06 GMT
14 RxHeader b Server: Apache
14 RxHeader b Vary: Accept-Encoding
14 RxHeader b Content-Encoding: gzip
14 RxHeader b Content-Length: 243
14 RxHeader b Connection: close
14 RxHeader b Content-Type: text/html; charset=iso-8859-1
12 TTL c 1884874126 RFC 120 1329319174 0 0 0 0
12 VCL_call c fetch
12 VCL_return c pass
12 ObjProtocol c HTTP/1.1
12 ObjStatus c 404
12 ObjResponse c Not Found
12 ObjHeader c Date: Wed, 15 Feb 2012 15:20:06 GMT
12 ObjHeader c Server: Apache
12 ObjHeader c Vary: Accept-Encoding
12 ObjHeader c Content-Encoding: gzip
12 ObjHeader c Content-Type: text/html; charset=iso-8859-1
14 Length b 243
14 BackendClose b default
12 VCL_call c deliver
12 VCL_return c deliver
12 TxProtocol c HTTP/1.1
12 TxStatus c 404
12 TxResponse c Not Found
12 TxHeader c Server: Apache
12 TxHeader c Vary: Accept-Encoding
12 TxHeader c Content-Encoding: gzip
12 TxHeader c Content-Type: text/html; charset=iso-8859-1
12 TxHeader c Content-Length: 243
12 TxHeader c Date: Wed, 15 Feb 2012 15:19:34 GMT
12 TxHeader c X-Varnish: 1884874126
12 TxHeader c Age: 0
12 TxHeader c Via: 1.1 varnish
12 TxHeader c Connection: close
12 Length c 243
12 ReqEnd c 1884874126 1329319174.638826609 1329319174.639825106 0.000061750 0.000943899 0.000054598
12 SessionClose c Connection: close
12 StatSess c 127.0.0.1 54334 0 1 1 0 1 1 260 243
0 CLI - Rd ping
0 CLI - Wr 200 PONG 1329319176 1.0
HAProxy is the default backend.
Could it also have something to do with the fact that HAProxy does not log subsequent requests for the same session? I assumed since HAProxy did not log them, they didn't pass through it, but according to the docs this is intended behavior. Since Varnish is the client as far as HAProxy is concerned, multiple requests (from multiple visitors) can belong to the same session?
Edit 2: It appears that if I add
option forceclose
option http-pretend-keepalive
to my HAProxy configuration the problem disappears or becomes much less frequent. This feels like a workaround to a deeper problem regarding Varnish / HAProxy interaction. Varnish receives a Connection: Close header, but does not specify that header in the request to the backend. Force closing the connection makes sure HAProxy evaluates every single request from Varnish.
0 Answers