Long accpet time issue in varnish 2.1.5
xwu
goafter1981 at gmail.com
Wed Jun 1 02:41:51 CEST 2011
Dear folks,
In our varnish settings, we wait for long time to get response from
varnish frequently. From Reqend log, we have the following finding:
The '824436860' transaction takes 193.6 seconds from accepting request
to dealing with request. I am not sure what's wrong. I'll supplement my
vcl and start paremeter in the bottom.
0 WorkThread - 0x7f848dbfcbc0 start
30 ReqStart c 119.167.245.10 2539 824436860
30 RxRequest c GET
30 RxURL
c /javascripts/jquery/jquery.backgroundPosition.js?1306827037
30 RxProtocol c HTTP/1.1
30 RxHeader c Host: dev.yottaa.com.try.yottaa.net
30 RxHeader c User-Agent: YottaaMonitor
30 RxHeader c Accept: */*
30 RxHeader c Accept-Language: en-us,en;q=0.5
30 RxHeader c Accept-Encoding: gzip,deflate
30 RxHeader c Accept-Charset: ISO-8859-1,utf-8;q=0.7,*;q=0.7
30 RxHeader c Keep-Alive: 115
30 RxHeader c Connection: keep-alive
30 RxHeader c Referer: http://dev.yottaa.com.try.yottaa.net/
30 RxHeader c Cookie: y=b92319a06dcf012ebe4712313909bca1;
_dpu_session=BAh7CDoQX2NzcmZfdG9rZW4iMU9vK3VEK2wxUUlMWDR2M2NDMUc5ZTQrM2NDN1p4VVk5N0dKNlVHYm5FUzg9OhN1c2VyLnJldHVybl90byIGLzoPc2Vzc2lvbl9pZCIlNTA3ZDE5ODBjYzZlMzk0YTI2ZWE0YmQyNWEyZTg2MmM%3D--97597402d695f4c7a7b7dd
30 VCL_call c recv
30 VCL_return c pass
30 VCL_call c hash
30 VCL_return c hash
30 VCL_call c pass
30 VCL_return c pass
30 Backend c 23 yo a
23 TxRequest b GET
23 TxURL
b /javascripts/jquery/jquery.backgroundPosition.js?1306827037
23 TxProtocol b HTTP/1.1
23 TxHeader b Host: dev.yottaa.com.try.yottaa.net
23 TxHeader b User-Agent: YottaaMonitor
23 TxHeader b Accept: */*
23 TxHeader b Accept-Language: en-us,en;q=0.5
23 TxHeader b Accept-Encoding: gzip,deflate
23 TxHeader b Accept-Charset: ISO-8859-1,utf-8;q=0.7,*;q=0.7
23 TxHeader b Referer: http://dev.yottaa.com.try.yottaa.net/
23 TxHeader b Cookie: y=b92319a06dcf012ebe4712313909bca1;
_dpu_session=BAh7CDoQX2NzcmZfdG9rZW4iMU9vK3VEK2wxUUlMWDR2M2NDMUc5ZTQrM2NDN1p4VVk5N0dKNlVHYm5FUzg9OhN1c2VyLnJldHVybl90byIGLzoPc2Vzc2lvbl9pZCIlNTA3ZDE5ODBjYzZlMzk0YTI2ZWE0YmQyNWEyZTg2MmM%3D--97597402d695f4c7a7b7dd
23 TxHeader b X-Forwarded-For: 119.167.245.10
23 TxHeader b X-Varnish: 824436860
23 RxProtocol b HTTP/1.1
23 RxStatus b 200
23 RxResponse b OK
23 RxHeader b Server: nginx/0.8.54
23 RxHeader b Date: Tue, 31 May 2011 07:33:41 GMT
23 RxHeader b Content-Type: application/x-javascript
23 RxHeader b Last-Modified: Tue, 31 May 2011 07:30:37 GMT
23 RxHeader b Vary: Accept-Encoding
23 RxHeader b Expires: Thu, 31 Dec 2037 23:55:55 GMT
23 RxHeader b Cache-Control: max-age=315360000
23 RxHeader b Content-Encoding: deflate
23 RxHeader b Content-Length: 807
23 RxHeader b X-Yottaa-Cache: hit
23 RxHeader b X-Yottaa-Timestamp: 12345678911
23 RxHeader b X-Yottaa-Optimizations: compression
23 RxHeader b X-Yottaa-Timings: 0,620,620
23 RxHeader b X-Yottaa-SessionId:
b2a163ef-b80d-46bd-bb7e-e27e3b0d3d08
23 RxHeader b X-Yottaa-V2R-Thread: 49
23 RxHeader b X-Yottaa-R2O-Thread: hit-in-cache?
30 TTL c 824436860 RFC 315360000 1306858991 0 0 315360000 0
30 VCL_call c fetch
30 VCL_Log c enter fetch
30 VCL_Log c hit
30 TTL c 824436
30 ObjProtocol c HTTP/1.1
30 ObjStatus c 200
30 ObjResponse c OK
30 ObjHeader c Server: nginx/0.8.54
30 ObjHeader c Date: Tue, 31 May 2011 07:33:41 GMT
30 ObjHeader c Content-Type: application/x-javascript
30 ObjHeader c Last-Modified: Tue, 31 May 2011 07:30:37 GMT
30 ObjHeader c Vary: Accept-Encoding
30 ObjHeader c Expires: Thu, 31 Dec 2037 23:55:55 GMT
30 ObjHeader c Cache-Control: max-age=315360000
30 ObjHeader c Content-Encoding: deflate
30 ObjHeader c Content-Length: 807
30 ObjHeader c X-Yottaa-Cache: hit
30 ObjHeader c X-Yottaa-Timestamp: 12345678911
30 ObjHeader c X-Yottaa-Optimizations: compression
30 ObjHeader c X-Yottaa-Timings: 0,620,620
30 ObjHeader c X-Yottaa-SessionId:
b2a163ef-b80d-46bd-bb7e-e27e3b0d3d08
30 ObjHeader c X-Yottaa-V2R-Thread: 49
30 ObjHeader c X-Yottaa-R2O-Thread: hit-in-cache?
23 Fetch_Body b 4 0 1
23 Length b 807
23 BackendReuse b a
30 VCL_call c deliver
30 VCL_return c deliver
30 TxProtocol c HTTP/1.1
30 TxStatus c 200
30 TxResponse c OK
30 TxHeader c Server: nginx/0.8.54
30 TxHeader c Content-Type: application/x-javascript
30 TxHeader c Last-Modified: Tue, 31 May 2011 07:30:37 GMT
30 TxHeader c Vary: Accept-Encoding
30 TxHeader c Expires: Thu, 31 Dec 2037 23:55:55 GMT
30 TxHeader c Cache-Control: max-age=315360000
30 TxHeader c Content-Encoding: deflate
30 TxHeader c X-Yottaa-Cache: hit
30 TxHeader c X-Yottaa-Timestamp: 12345678911
30 TxHeader c X-Yottaa-Optimizations: compression
30 TxHeader c X-Yottaa-Timings: 0,620,620
30 TxHeader c X-Yottaa-SessionId:
b2a163ef-b80d-46bd-bb7e-e27e3b0d3d08
30 TxHeader c X-Yottaa-V2R-Thread: 49
30 TxHeader c X-Yottaa-R2O-Thread: hit-in-cache?
30 TxHeader c Content-Length: 807
30 TxHeader c Date: Tue, 31 May 2011 16:23:11 GMT
30 TxHeader c X-Varnish: 824436860
30 TxHeader c Age: 0
30 TxHeader c Via: 1.1 varnish
30 TxHeader c Connection: keep-alive
30 TxHeader c X-Cache: MISS
30 Length c 807
30 ReqEnd c 824436860 1306858991.862764597 1306858991.865270615
193.628781319 0.002455711 0.000050306
/usr/sbin/varnishd -P /var/run/varnish.pid -a :80
-f /etc/varnish/yottaa.vcl -T 127.0.0.1:6082 -t 120 -w 1,1000,120 -u
varnish -g varnish -s malloc,5
Below is the VCL configuration:
backend a {
.host = "192.168.1.1";
.port = "80";
.probe = {
.request =
"TRACE / HTTP/1.1"
"Max-Forwards: 0"
"Connection: close";
.timeout = 0.3 s;
.window = 5;
.threshold = 3;
}
.connect_timeout = 2s;
.first_byte_timeout = 330s;
.between_bytes_timeout = 330s;
}
backend b {
.host = "192.168.1.2";
.port = "80";
.probe = {
.request =
"TRACE / HTTP/1.1"
"Max-Forwards: 0"
"Connection: close";
.timeout = 0.3 s;
.window = 5;
.threshold = 3;
}
.connect_timeout = 2s;
.first_byte_timeout = 330s;
.between_bytes_timeout = 330s;
}
director yo client {
{
.backend = a;
.weight = 1;
}
{
.backend = b;
.weight = 1;
}
}
sub vcl_recv {
if (req.url ~ "\.(png|gif|jpg|swf|css|js)$") {
unset req.http.cookie;
}
if (req.backend.healthy) {
set req.grace = 30s;
} else {
set req.grace = 1h;
}
set req.backend = yo;
/* Load balance by user agent */
set client.identity = req.http.host;
}
sub vcl_fetch {
set beresp.grace = 1h;
log "enter fetch";
log beresp.http.X-y-Cache;
if (beresp.http.X-y-Cache && !beresp.http.X-y-Cache ~ "hit") {
log "Cache miss from tpu";
log "set ttl 0s " ;
set beresp.ttl= 0s;
return (pass);
}
if (!beresp.cacheable) {
set beresp.ttl= 0s;
return (pass);
}
if (beresp.http.Set-Cookie) {
set beresp.ttl= 0s;
return (pass);
}
if (beresp.http.Content-Type && beresp.http.Content-Type ~ "html" ) {
return (pass);
}
return (deliver);
}
sub vcl_deliver {
if (obj.hits > 0) {
set resp.http.X-Cache = "HIT";
} else {
set resp.http.X-Cache = "MISS";
}
return (deliver);
}
More information about the varnish-misc
mailing list