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); } _______________________________________________ varnish-misc mailing list [email protected] http://www.varnish-cache.org/lists/mailman/listinfo/varnish-misc
