HEAD redirects for HTTP/1.0 backend locally?
Tom Pepper
tom at razz.com
Thu Sep 13 03:42:26 CEST 2007
Sirs:
I'm seeing some interesting behavior w/r/t HEAD requests that I'd
appreciate some insights on. Some background:
We use a foundry serveriron GT for load balancing. Its IP is
192.168.10.254.
The varnish test server is 192.168.10.101 under fedora 7, compiled
from source.
The current back-end server is nyp-web-1.corp.razz.com, at
192.168.10.80.
The foundry makes health checks to varnish every 5 seconds via HEAD
requests using HTTP/1.0.
For some reason (unless I'm interpreting this wrong), varnish is
deciding that the backend of these HEAD requests should be itself,
and the timestamp on the lookup is off by several hours:
(from varnishncsa)
192.168.10.254 - - [12/Sep/2007:18:32:28 -0700] "HEAD /static/mixer/
playerdefault.swf HTTP/1.0" 200 61986 "-" "-"
192.168.10.254 - - [12/Sep/2007:18:32:33 -0700] "HEAD /static/mixer/
playerdefault.swf HTTP/1.0" 200 61986 "-" "-"
192.168.10.254 - - [12/Sep/2007:18:32:38 -0700] "HEAD /static/mixer/
playerdefault.swf HTTP/1.0" 200 61986 "-" "-"
192.168.10.101 - - [13/Sep/2007:01:32:43 -0700] "GET http://nyp-
web-1.corp.razz.com/mixer/playerdefault.swf HTTP/1.1" 200 61986 "-" "-"
192.168.10.254 - - [12/Sep/2007:18:32:43 -0700] "HEAD /static/mixer/
playerdefault.swf HTTP/1.0" 200 61986 "-" "-"
192.168.10.254 - - [12/Sep/2007:18:32:48 -0700] "HEAD /static/mixer/
playerdefault.swf HTTP/1.0" 200 61986 "-" "-"
192.168.10.254 - - [12/Sep/2007:18:32:53 -0700] "HEAD /static/mixer/
playerdefault.swf HTTP/1.0" 200 61986 "-" "-"
The GET request is varnish connecting to itself to check the asset
when the ttl expires. This request should instead be hitting the
backend server.
Current config:
backend default {
set backend.host = "nyp-web-1.corp.razz.com";
set backend.port = "80";
}
sub vcl_recv {
set req.backend = default;
set req.http.host = "nyp-web-1.corp.razz.com";
// block redirect loops
if (req.url ~ "^/static/static/") {
error 404 "Not found.";
}
// change all /static/ requests into / backend requests
if (req.url ~ "^/static/") {
set req.url = regsub(req.url, "^/static/", "/");
}
// strip query parameters from all swf requests (so they cache
as a single object)
if (req.url ~ "\.swf\?.*") {
set req.url = regsub(req.url, "\.swf\?.*", ".swf");
}
// force lookup on any of the static object types
if (req.url ~ "\.(swf|gif|jpg|png|js|bmp|pdf|css|mp3|xml|flv)
(\?.*)?$") {
lookup;
}
// deny any other kind of request
error 404 "Not found.";
}
Here's the output of varnishlog for the HEAD requests surrounding the
GET:
0 CLI Rd ping
0 CLI Wr 0 200 PONG 1189647149
0 CLI Rd ping
0 CLI Wr 0 200 PONG 1189647152
15 SessionOpen c 192.168.10.254 1720
15 ReqStart c 192.168.10.254 1720 1052036059
15 RxRequest c HEAD
15 RxURL c /static/mixer/playerdefault.swf
15 RxProtocol c HTTP/1.0
15 VCL_call c recv
15 VCL_trace c 1 7.14
15 VCL_trace c 2 13.9
15 VCL_trace c 4 18.5
15 VCL_trace c 5 18.9
15 VCL_trace c 6 18.32
15 VCL_trace c 7 23.5
15 VCL_trace c 8 23.9
15 VCL_trace c 10 28.5
15 VCL_trace c 11 28.9
15 VCL_trace c 12 28.77
15 VCL_return c lookup
15 VCL_call c hash
15 VCL_trace c 41 22.14
15 VCL_return c hash
15 Hit c 1052036036
15 VCL_call c hit
15 VCL_trace c 42 28.13
15 VCL_trace c 43 29.9
15 VCL_trace c 45 32.5
15 VCL_return c deliver
15 Length c 61986
15 VCL_call c deliver
15 VCL_trace c 57 51.17
15 VCL_return c deliver
15 TxProtocol c HTTP/1.1
15 TxStatus c 200
15 TxResponse c OK
15 TxHeader c Date: Thu, 13 Sep 2007 01:30:38 GMT
15 TxHeader c Server: Apache/2.2.4 (Fedora)
15 TxHeader c Last-Modified: Thu, 26 Apr 2007 17:42:49 GMT
15 TxHeader c ETag: "3368c1-f222-42f078c1f9840"
15 TxHeader c Content-Type: application/x-shockwave-flash
15 TxHeader c X-Pad: avoid browser bug
15 TxHeader c Content-Length: 61986
15 TxHeader c X-Varnish: 1052036059 1052036036
15 TxHeader c Age: 115
15 TxHeader c Via: 1.1 varnish
15 TxHeader c Connection: close
15 ReqEnd c 1052036059 1189647153.765747786
1189647153.765867233 0.000073671 0.000063419 0.000056028
0 StatAddr 192.168.10.254 0 115 24 24 0 0 1 8199 0
15 SessionClose c not HTTP/1.1
15 StatSess c 192.168.10.254 1720 0 1 1 0 0 0 343 0
0 CLI Rd ping
0 CLI Wr 0 200 PONG 1189647155
0 CLI Rd ping
0 CLI Wr 0 200 PONG 1189647158
15 SessionOpen c 192.168.10.254 1727
15 ReqStart c 192.168.10.254 1727 1052036060
15 RxRequest c HEAD
15 RxURL c /static/mixer/playerdefault.swf
15 RxProtocol c HTTP/1.0
15 VCL_call c recv
15 VCL_trace c 1 7.14
15 VCL_trace c 2 13.9
15 VCL_trace c 4 18.5
15 VCL_trace c 5 18.9
15 VCL_trace c 6 18.32
15 VCL_trace c 7 23.5
15 VCL_trace c 8 23.9
15 VCL_trace c 10 28.5
15 VCL_trace c 11 28.9
15 VCL_trace c 12 28.77
15 VCL_return c lookup
15 VCL_call c hash
15 VCL_trace c 41 22.14
15 VCL_return c hash
15 Hit c 1052036036
15 VCL_call c hit
15 VCL_trace c 42 28.13
15 VCL_trace c 43 29.9
15 VCL_trace c 45 32.5
15 VCL_return c deliver
15 Length c 61986
15 VCL_call c deliver
15 VCL_trace c 57 51.17
15 VCL_return c deliver
15 TxProtocol c HTTP/1.1
15 TxStatus c 200
15 TxResponse c OK
15 TxHeader c Date: Thu, 13 Sep 2007 01:30:38 GMT
15 TxHeader c Server: Apache/2.2.4 (Fedora)
15 TxHeader c Last-Modified: Thu, 26 Apr 2007 17:42:49 GMT
15 TxHeader c ETag: "3368c1-f222-42f078c1f9840"
15 TxHeader c Content-Type: application/x-shockwave-flash
15 TxHeader c X-Pad: avoid browser bug
15 TxHeader c Content-Length: 61986
15 TxHeader c X-Varnish: 1052036060 1052036036
15 TxHeader c Age: 120
15 TxHeader c Via: 1.1 varnish
15 TxHeader c Connection: close
15 ReqEnd c 1052036060 1189647158.765828848
1189647158.765937805 0.000067711 0.000058413 0.000050545
0 StatAddr 192.168.10.254 0 120 25 25 0 0 1 8542 0
15 SessionClose c not HTTP/1.1
15 StatSess c 192.168.10.254 1727 0 1 1 0 0 0 343 0
0 ExpKill 1052036036 0
0 CLI Rd ping
0 CLI Wr 0 200 PONG 1189647161
15 SessionOpen c 192.168.10.254 1734
15 ReqStart c 192.168.10.254 1734 1052036061
15 RxRequest c HEAD
15 RxURL c /static/mixer/playerdefault.swf
15 RxProtocol c HTTP/1.0
15 VCL_call c recv
15 VCL_trace c 1 7.14
15 VCL_trace c 2 13.9
15 VCL_trace c 4 18.5
15 VCL_trace c 5 18.9
15 VCL_trace c 6 18.32
15 VCL_trace c 7 23.5
15 VCL_trace c 8 23.9
15 VCL_trace c 10 28.5
15 VCL_trace c 11 28.9
15 VCL_trace c 12 28.77
15 VCL_return c lookup
15 VCL_call c hash
15 VCL_trace c 41 22.14
15 VCL_return c hash
15 VCL_call c miss
15 VCL_trace c 46 35.14
15 VCL_return c fetch
18 BackendClose default
18 BackendOpen b default 192.168.10.101 45075 192.168.10.80 80
18 BackendXID b 1052036061
15 Backend c 18 default
18 TxRequest b GET
18 TxURL b /mixer/playerdefault.swf
18 TxProtocol b HTTP/1.1
18 TxHeader b host: nyp-web-1.corp.razz.com
18 TxHeader b X-Varnish: 1052036061
18 TxHeader b X-Forwarded-for: 192.168.10.254
18 RxProtocol b HTTP/1.1
18 RxStatus b 200
18 RxResponse b OK
18 RxHeader b Date: Thu, 13 Sep 2007 01:32:43 GMT
18 RxHeader b Server: Apache/2.2.4 (Fedora)
18 RxHeader b Last-Modified: Thu, 26 Apr 2007 17:42:49 GMT
18 RxHeader b ETag: "3368c1-f222-42f078c1f9840"
18 RxHeader b Accept-Ranges: bytes
18 RxHeader b Content-Length: 61986
18 RxHeader b Content-Type: application/x-shockwave-flash
18 RxHeader b X-Pad: avoid browser bug
15 ObjProtocol c HTTP/1.1
15 ObjStatus c 200
15 ObjResponse c OK
15 ObjHeader c Date: Thu, 13 Sep 2007 01:32:43 GMT
15 ObjHeader c Server: Apache/2.2.4 (Fedora)
15 ObjHeader c Last-Modified: Thu, 26 Apr 2007 17:42:49 GMT
15 ObjHeader c ETag: "3368c1-f222-42f078c1f9840"
15 ObjHeader c Content-Type: application/x-shockwave-flash
15 ObjHeader c X-Pad: avoid browser bug
18 BackendReuse b default
15 TTL c 1052036061 RFC 120 1189647163 1189647163 0 0 0
15 VCL_call c fetch
15 VCL_trace c 14 37.15
15 VCL_trace c 15 39.9
15 VCL_trace c 17 43.5
15 VCL_trace c 18 43.9
15 VCL_trace c 20 47.5
15 VCL_trace c 21 47.9
15 VCL_trace c 23 51.5
15 VCL_trace c 24 51.9
15 VCL_trace c 26 55.5
15 VCL_return c insert
15 Length c 61986
15 VCL_call c deliver
15 VCL_trace c 57 51.17
15 VCL_return c deliver
15 TxProtocol c HTTP/1.1
15 TxStatus c 200
15 TxResponse c OK
15 TxHeader c Date: Thu, 13 Sep 2007 01:32:43 GMT
15 TxHeader c Server: Apache/2.2.4 (Fedora)
15 TxHeader c Last-Modified: Thu, 26 Apr 2007 17:42:49 GMT
15 TxHeader c ETag: "3368c1-f222-42f078c1f9840"
15 TxHeader c Content-Type: application/x-shockwave-flash
15 TxHeader c X-Pad: avoid browser bug
15 TxHeader c Content-Length: 61986
15 TxHeader c X-Varnish: 1052036061
15 TxHeader c Age: 0
15 TxHeader c Via: 1.1 varnish
15 TxHeader c Connection: close
15 ReqEnd c 1052036061 1189647163.765805483
1189647163.767508268 0.000074863 0.001671553 0.000031233
0 StatAddr 192.168.10.254 0 125 26 26 0 0 2 8872 0
15 SessionClose c not HTTP/1.1
15 StatSess c 192.168.10.254 1734 0 1 1 0 0 1 330 0
0 CLI Rd ping
0 CLI Wr 0 200 PONG 1189647164
0 CLI Rd ping
0 CLI Wr 0 200 PONG 1189647167
15 SessionOpen c 192.168.10.254 1741
15 ReqStart c 192.168.10.254 1741 1052036062
15 RxRequest c HEAD
15 RxURL c /static/mixer/playerdefault.swf
15 RxProtocol c HTTP/1.0
15 VCL_call c recv
15 VCL_trace c 1 7.14
15 VCL_trace c 2 13.9
15 VCL_trace c 4 18.5
15 VCL_trace c 5 18.9
15 VCL_trace c 6 18.32
15 VCL_trace c 7 23.5
15 VCL_trace c 8 23.9
15 VCL_trace c 10 28.5
15 VCL_trace c 11 28.9
15 VCL_trace c 12 28.77
15 VCL_return c lookup
15 VCL_call c hash
15 VCL_trace c 41 22.14
15 VCL_return c hash
15 Hit c 1052036061
15 VCL_call c hit
15 VCL_trace c 42 28.13
15 VCL_trace c 43 29.9
15 VCL_trace c 45 32.5
15 VCL_return c deliver
15 Length c 61986
15 VCL_call c deliver
15 VCL_trace c 57 51.17
15 VCL_return c deliver
15 TxProtocol c HTTP/1.1
15 TxStatus c 200
15 TxResponse c OK
15 TxHeader c Date: Thu, 13 Sep 2007 01:32:43 GMT
15 TxHeader c Server: Apache/2.2.4 (Fedora)
15 TxHeader c Last-Modified: Thu, 26 Apr 2007 17:42:49 GMT
15 TxHeader c ETag: "3368c1-f222-42f078c1f9840"
15 TxHeader c Content-Type: application/x-shockwave-flash
15 TxHeader c X-Pad: avoid browser bug
15 TxHeader c Content-Length: 61986
15 TxHeader c X-Varnish: 1052036062 1052036061
15 TxHeader c Age: 5
15 TxHeader c Via: 1.1 varnish
15 TxHeader c Connection: close
15 ReqEnd c 1052036062 1189647168.765779495
1189647168.765885353 0.000075102 0.000062466 0.000043392
0 StatAddr 192.168.10.254 0 130 27 27 0 0 2 9213 0
15 SessionClose c not HTTP/1.1
15 StatSess c 192.168.10.254 1741 0 1 1 0 0 0 341 0
0 CLI Rd ping
0 CLI Wr 0 200 PONG 1189647170
0 CLI Rd ping
0 CLI Wr 0 200 PONG 1189647173
15 SessionOpen c 192.168.10.254 1748
15 ReqStart c 192.168.10.254 1748 1052036063
15 RxRequest c HEAD
15 RxURL c /static/mixer/playerdefault.swf
15 RxProtocol c HTTP/1.0
15 VCL_call c recv
15 VCL_trace c 1 7.14
15 VCL_trace c 2 13.9
15 VCL_trace c 4 18.5
15 VCL_trace c 5 18.9
15 VCL_trace c 6 18.32
15 VCL_trace c 7 23.5
15 VCL_trace c 8 23.9
15 VCL_trace c 10 28.5
15 VCL_trace c 11 28.9
15 VCL_trace c 12 28.77
15 VCL_return c lookup
15 VCL_call c hash
15 VCL_trace c 41 22.14
15 VCL_return c hash
15 Hit c 1052036061
15 VCL_call c hit
15 VCL_trace c 42 28.13
15 VCL_trace c 43 29.9
15 VCL_trace c 45 32.5
15 VCL_return c deliver
15 Length c 61986
15 VCL_call c deliver
15 VCL_trace c 57 51.17
15 VCL_return c deliver
15 TxProtocol c HTTP/1.1
15 TxStatus c 200
15 TxResponse c OK
15 TxHeader c Date: Thu, 13 Sep 2007 01:32:43 GMT
15 TxHeader c Server: Apache/2.2.4 (Fedora)
15 TxHeader c Last-Modified: Thu, 26 Apr 2007 17:42:49 GMT
15 TxHeader c ETag: "3368c1-f222-42f078c1f9840"
15 TxHeader c Content-Type: application/x-shockwave-flash
15 TxHeader c X-Pad: avoid browser bug
15 TxHeader c Content-Length: 61986
15 TxHeader c X-Varnish: 1052036063 1052036061
15 TxHeader c Age: 10
15 TxHeader c Via: 1.1 varnish
15 TxHeader c Connection: close
15 ReqEnd c 1052036063 1189647173.765821457
1189647173.765940905 0.000079632 0.000065804 0.000053644
0 StatAddr 192.168.10.254 0 135 28 28 0 0 2 9555 0
15 SessionClose c not HTTP/1.1
15 StatSess c 192.168.10.254 1748 0 1 1 0 0 0 342 0
Footnote: it looks like requests from the wild are behaving similarly:
192.168.10.254 - - [12/Sep/2007:18:40:23 -0700] "HEAD /static/mixer/
playerdefault.swf HTTP/1.0" 200 61986 "-" "-"
192.168.10.254 - - [12/Sep/2007:18:40:28 -0700] "HEAD /static/mixer/
playerdefault.swf HTTP/1.0" 200 61986 "-" "-"
127.0.0.1 - - [12/Sep/2007:18:40:28 -0700] "(null) (null)
(null)" (null) (null) "-" "-"
192.168.10.101 - - [13/Sep/2007:01:40:30 -0700] "GET http://nyp-
web-1.corp.razz.com/mixer/player8a.swf HTTP/1.1" 200 59986 "-"
"Mozilla/5.0 (Macintosh; U; Intel Mac OS X; en) AppleWebKit/522.11.1
(KHTML, like Gecko) Version/3.0.3 Safari/522.12.1"
208.106.97.31 - - [12/Sep/2007:18:40:30 -0700] "GET http://
www.razz.com/static/mixer/player8a.swf?u=2743&s=1&o=2743 HTTP/1.1"
200 59986 "-" "Mozilla/5.0 (Macintosh; U; Intel Mac OS X; en)
AppleWebKit/522.11.1 (KHTML, like Gecko) Version/3.0.3 Safari/522.12.1"
127.0.0.1 - - [13/Sep/2007:01:40:31 -0700] "GET http://nyp-
web-1.corp.razz.com/mixer/saved/1/1/1/e0ca0476.flv HTTP/1.1" 200
107712 "http://www.razz.com/static/mixer/player8a.swf?
u=2743&s=1&o=2743" "Mozilla/5.0 (Macintosh; U; Intel Mac OS X; en)
AppleWebKit/522.11.1 (KHTML, like Gecko) Version/3.0.3 Safari/522.12.1"
208.106.97.31 - - [12/Sep/2007:18:40:32 -0700] "GET http://
www.razz.com/static/mixer/saved/1/1/1/e0ca0476.flv HTTP/1.1" 200
107712 "http://www.razz.com/static/mixer/player8a.swf?
u=2743&s=1&o=2743" "Mozilla/5.0 (Macintosh; U; Intel Mac OS X; en)
AppleWebKit/522.11.1 (KHTML, like Gecko) Version/3.0.3 Safari/522.12.1"
192.168.10.254 - - [12/Sep/2007:18:40:33 -0700] "HEAD /static/mixer/
playerdefault.swf HTTP/1.0" 200 61986 "-" "-"
Thanks for your consideration!
-Tom
More information about the varnish-misc
mailing list