<HTML>
<HEAD>
<TITLE>Re: Varnish child killed</TITLE>
</HEAD>
<BODY>
<FONT SIZE="4"><FONT FACE="Calibri, Verdana, Helvetica, Arial"><SPAN STYLE='font-size:11pt'>Hi Geoff,<BR>
<BR>
1. <B>You’re completely true about guesses !<BR>
</B>In fact it’s very hard for me to get anything valuable from the logs in order to point a guilty !<BR>
<BR>
I can just tell what I can see from cacti graphs and correlate with the behavior of varnish.<BR>
<BR>
What is the way in your opinion to have a better idea on what’s going on ? At this stage I’m just open to any idea ! <BR>
Please don’t tell me to run varnish in debug mode in production ;-)<BR>
<BR>
I am just trying to explain what I can see as there was some obvious paterns (out of cacti graphs):<BR>
Impossible to go higher the 25Gb of cache used. You can clearly see that the shared memory used is increasing gradually until 25G and can’t go higher.<BR>
I believe there is some more objects to cache but varnish can’t for any reason.<BR>
Impossible to go above 1 million object cached. Same observation as the shared memory.<BR>
<BR>
<B>2. hitratio<BR>
</B>My hit ratio is pretty low around 50%.<BR>
It used to be around 70% with the version 2.0.6 and dropped down to 50%.<BR>
I can’t explain it as what was changed was only :<BR>
In vcl_fetch, replace obj by beresp<BR>
Replace calls to pass or deliver by return(deliver) or return(pass)<BR>
<BR>
Attached is a graph in order to give you an idea about hit ratio:<BR>
<IMG src="cid:3386244047_6496850" ><BR>
<BR>
On the left side you see of the graph you see the hitrate when using 2.0.6 and on right side after upgrading.<BR>
<BR>
Here is my vcl:<BR>
backend default {<BR>
.host = "172.20.102.55";<BR>
.port = "8080";<BR>
.connect_timeout = 60s;<BR>
.first_byte_timeout = 60s;<BR>
.between_bytes_timeout = 600s;<BR>
}<BR>
sub vcl_recv {<BR>
<BR>
unset req.http.Cookie;<BR>
remove req.http.X-Forwarded-For;<BR>
set req.http.X-Forwarded-For = client.ip;<BR>
set req.grace = 1m;<BR>
if (req.url ~ "^/is-alive") {<BR>
error 750 "Up";<BR>
}<BR>
<BR>
if (req.http.Authenticate) {<BR>
return (pass);<BR>
}<BR>
<BR>
if (req.url ~ "^http://") {<BR>
set req.url = regsub(req.url, "<a href="http://[^/]*">http://[^/]*</a>", "");<BR>
}<BR>
<BR>
if (req.http.host ~ "static.ece.tsr.ch") {<BR>
return (pass);<BR>
}<BR>
<BR>
if (req.http.host == "ece.tsr.ch" && req.url !~ "^/robots.txt") {<BR>
set req.http.host = "www.tsr.ch";<BR>
}<BR>
<BR>
if (req.url ~ "^/tsr/.+/index\.html") {<BR>
set req.url = regsub(req.url, "^/tsr/.+/index\.html", "/tsr/index.html");<BR>
}<BR>
<BR>
if (req.url ~ "&") {<BR>
set req.url = regsuball(req.url, "&", "&");<BR>
}<BR>
<BR>
<BR>
if (req.request == "GET" || req.request == "HEAD") {<BR>
return (lookup);<BR>
}<BR>
}<BR>
sub vcl_error {<BR>
if (obj.status == 750) {<BR>
set obj.http.Content-Type = "text/plain; charset=utf-8";<BR>
synthetic {"escenic-up"};<BR>
return (deliver);<BR>
}<BR>
<BR>
}<BR>
sub vcl_fetch {<BR>
<BR>
unset beresp.http.x-ece-cache;<BR>
set beresp.http.X-ece-cache = server.hostname;<BR>
set beresp.grace = 1m;<BR>
<BR>
unset beresp.http.X-ece-was-cached;<BR>
<BR>
# respect no-cache from the backend<BR>
if (beresp.http.Cache-Control ~ "no-cache") {<BR>
set beresp.http.X-ece-was-cached = "backend no-cache";<BR>
return (pass);<BR>
}<BR>
#respect custom cache from the backend<BR>
if (beresp.http.X-Ece-Cache-Control ~ "custom") {<BR>
unset beresp.http.X-Ece-Cache-Control;<BR>
set beresp.http.X-ece-was-cached = "backend custom cache";<BR>
return (deliver);<BR>
}<BR>
<BR>
unset beresp.http.cache-control;<BR>
unset beresp.http.expires;<BR>
unset beresp.http.pragma;<BR>
unset beresp.http.Set-Cookie;<BR>
<BR>
# errors cache 5 min ttl + 2 min akamai<BR>
if (beresp.status == 403 || beresp.status == 404 || beresp.status == 500 || beresp.status == 503) {<BR>
set beresp.http.Cache-Control = "max-age=120";<BR>
set beresp.http.X-ece-was-cached = "errors: 5m ttl, max-age=120, age 0";<BR>
set beresp.ttl = 5m;<BR>
<BR>
# short cache 60 sec ttl + 60 sec akamai<BR>
} else if ( req.url == "/" || req.url == "/info/" || req.url == "/sport/" ) {<BR>
set beresp.http.Cache-Control = "max-age=60";<BR>
set beresp.http.X-ece-was-cached = "short: 60s, max-age=60, age 0";<BR>
set beresp.ttl = 60s;<BR>
<BR>
# very long cache 90 days ttl + 1 week akamai<BR>
} else if (<BR>
beresp.status == 301 || # redirects<BR>
req.url ~ "^/[0-9]{4}/[0-9]{2}/.+\.image($|\?)" || # images, see CMS-4354<BR>
req.url ~ "\?format=(css|js)&.*cKey=" # javascript or css with cache key<BR>
) {<BR>
set beresp.http.Cache-Control = "max-age=604800";<BR>
set beresp.http.X-ece-was-cached = "very-long: 90d ttl, max-age=604800, age 0";<BR>
set beresp.ttl = 90d;<BR>
} else if (req.url ~ "\?.*page=[0-9]+") {<BR>
set beresp.http.Cache-Control = "max-age=7200";<BR>
set beresp.http.X-ece-was-cached = "intermediate: 22h ttl, max-age=7200, age 0";<BR>
set beresp.ttl = 22h;<BR>
<BR>
# medium cache 24h ttl + 24h akamai<BR>
} else if (req.url ~ "\.(image|gif|jpg|jpe|css|js|png|swf|ico)($|\?)") {<BR>
set beresp.http.Cache-Control = "max-age=86400";<BR>
set beresp.http.X-ece-was-cached = "medium: 1d ttl, max-age=86400, age 0";<BR>
set beresp.ttl = 1d;<BR>
<BR>
# default cache 10 min ttl + 5 min akamai<BR>
} else {<BR>
set beresp.http.Cache-Control = "max-age=300";<BR>
set beresp.http.X-ece-was-cached = "default: 10m ttl, max-age 300, age 0";<BR>
set beresp.ttl = 10m;<BR>
} <BR>
return (deliver);<BR>
}<BR>
<BR>
Here are my varnish startup options:<BR>
/usr/sbin/varnishd -P /var/run/varnish.pid -a :80 -f /etc/varnish/default.vcl -T 0.0.0.0:6082 -t 120 -w 100,3000,120 -u varnish -g varnish -s file,/var/lib/varnish/varnish_storage.bin,50G -p thread_pools 4 -p thread_pool_add_delay 2 -p cli_timeout 20 -p session_linger 50/100/150<BR>
<BR>
<BR>
3. <B>high load situation:<BR>
</B></SPAN></FONT></FONT><UL><LI><FONT SIZE="4"><FONT FACE="Calibri, Verdana, Helvetica, Arial"><SPAN STYLE='font-size:11pt'>only varnish is running on this server no apache or whatever, there is no other process using resources as varnish does.
</SPAN></FONT></FONT><LI><FONT SIZE="4"><FONT FACE="Calibri, Verdana, Helvetica, Arial"><SPAN STYLE='font-size:11pt'>varnish was not restarted before, you would have see it in the graph sent in my previous email because the number of objects would have dropped to zero and for sure message in the logs
</SPAN></FONT></FONT><LI><FONT SIZE="4"><FONT FACE="Calibri, Verdana, Helvetica, Arial"><SPAN STYLE='font-size:11pt'>command line settings: as specified earlier, I only have a 20s timeout, should I specify something else or more parameters ?
</SPAN></FONT></FONT><LI><FONT SIZE="4"><FONT FACE="Calibri, Verdana, Helvetica, Arial"><SPAN STYLE='font-size:11pt'>there is no panic message in the logs<BR>
</SPAN></FONT></FONT></UL><FONT SIZE="4"><FONT FACE="Calibri, Verdana, Helvetica, Arial"><SPAN STYLE='font-size:11pt'><BR>
You’re still completely about this statement:<BR>
</SPAN></FONT><FONT FACE="Consolas, Courier New, Courier"><SPAN STYLE='font-size:10pt'>The real question is why the Varnish child was no longer responding to pings.<BR>
<BR>
In the end my real question is :<BR>
<B>How could I trace child activity ?<BR>
</B><BR>
<BR>
Cheers,<BR>
<BR>
Jef<BR>
</SPAN></FONT><FONT FACE="Calibri, Verdana, Helvetica, Arial"><SPAN STYLE='font-size:11pt'><BR>
Le 21/04/11 13:42, « Geoff Simmons » a écrit :<BR>
<BR>
</SPAN></FONT></FONT><BLOCKQUOTE><FONT SIZE="4"><FONT FACE="Consolas, Courier New, Courier"><SPAN STYLE='font-size:10pt'>-----BEGIN PGP SIGNED MESSAGE-----<BR>
Hash: SHA256<BR>
<BR>
On 4/21/11 10:51 AM, Jean-Francois Laurens wrote:<BR>
> <BR>
> We’re run varnish 2.1.5 for some week now and we still do not understand<BR>
> some behavior regarding the shared memory activity.<BR>
<BR>
There's not enough information here for anything better than guesses<BR>
about what's going on.<BR>
<BR>
> We specified a –sfile,/var/lib/varnish/varnish_storage.bin,50G in the<BR>
> configuration but it’s impossible to go higher than 25G used by varnish.<BR>
[...]<BR>
> <BR>
> In addition I can see varnish doesn’t seem to be able to handle more<BR>
> than 1 million objects:<BR>
<BR>
It's not uncommon for Varnish to use significantly less memory than what<BR>
was allocated, but not because Varnish can't "handle" it, but just<BR>
because it works out that way. Due to a combination of factors like<BR>
usage patterns, TTLs, your command line settings and your VCL, Varnish<BR>
may decide that it doesn't need more than that.<BR>
<BR>
What do your cache hit ratios say? Do the logs or varnishstat give any<BR>
indication that objects are not being cached when you think they should<BR>
be? Do you have objects that, semantically, could be cached, but aren't<BR>
because, for example, they are unnecessarily setting cookies? You might<BR>
be able to get more into the cache more by tweaking VCL, but as I said,<BR>
that's just a guess.<BR>
<BR>
> When the child process get killed, the load of the system was very high:<BR>
> Apr 20 21:46:44 server-01-39 varnishd[21087]: Child (5372) not<BR>
> responding to CLI, killing it.<BR>
> ....<BR>
> Apr 20 21:49:57 server-01-39 nrpe[18101]: Command completed with return<BR>
> code 2 and output: CRITICAL -*load average: 159.00, 159.32,<BR>
> 77.02*|load1=159.000;15.000;30.000;0; load5=159.320;10.000;25.000;0;<BR>
> load15=77.020;5.000;20.000;0;<BR>
> ....<BR>
> Apr 20 21:48:43 server-01-39 varnishd[21087]: Child (5372) not<BR>
> responding to CLI, killing it.<BR>
<BR>
It looks like the message about high load came after the Varnish<BR>
processes died, and that might have happened, at least in part, because<BR>
Varnish was restarted and was getting nothing but cache misses. Unless<BR>
the high load was caused by something else. Which processes were showing<BR>
the highest CPU usage?<BR>
<BR>
The real question is why the Varnish child was no longer responding to<BR>
pings. Do you have any panic messages from Varnish in your syslog, or<BR>
anything else indicating the error? If the load was that high *before*<BR>
the processes died, your system might have been under so much stress<BR>
that the child processes just couldn't answer pings in time. In which<BR>
case your real problem might be something other than Varnish.<BR>
<BR>
> All this makes me believe we have an issue with some kernel parameters<BR>
> that do not allow varnish to handle as many objects as we configured it.<BR>
<BR>
It could be that, it could be another process that was causing heavy<BR>
load, it could be your VCL or your command line settings. Too many open<BR>
questions here.<BR>
<BR>
<BR>
Best,<BR>
Geoff<BR>
- -- <BR>
UPLEX Systemoptimierung<BR>
Schwanenwik 24<BR>
22087 Hamburg<BR>
<a href="http://uplex.de/">http://uplex.de/</a><BR>
Mob: +49-176-63690917<BR>
-----BEGIN PGP SIGNATURE-----<BR>
Version: GnuPG/MacGPG2 v2.0.14 (Darwin)<BR>
Comment: Using GnuPG with Mozilla - <a href="http://enigmail.mozdev.org/">http://enigmail.mozdev.org/</a><BR>
<BR>
iQIcBAEBCAAGBQJNsBgKAAoJEOUwvh9pJNURzS0QAJOvVWr3Yi4DsA2x0Ck+/HTa<BR>
pkL69dRhUskq5Ll6Ny+e0DBB9I3Dx48ZT9ZxzRcvIZQn4shPl1GPdQQRHCB0ek82<BR>
o8lLCdS/ta2HZhQI96FSUBj5RYDrPd3B78cAlvDLYzHsZIUbg90WmizHE/x9vPOi<BR>
z5TOS/0S3Ao7JIuqkMpkWYyVs4AH6aKIX1L9er9jYLbHp5s8R2ilzs3USeLdC8Kl<BR>
spGAaSn4mcCVHmhR+ZQ2XQjaf2nxN7oXEIviGOZOWfZ1XX1hQpDtjhp1D9BoInBW<BR>
oNZmamt6Hd+m00LCu88YhTiBMRDD7zbom9C0NWLf6n7LaCIQteM/KEo1z9tPLAS6<BR>
qmQzv+EvBKG5Dpcp81v5TqiUyVDzsYFegoKR6FKCCXvTlCI6avBlik1AlXRhecsF<BR>
27da7zMVvoDC44Wo+zqRkwMrtzpmE/Y55wdkP3YBUg/m4nzvci1VYTy3W436NfMe<BR>
ypjWJ+bQEL9erSURNVDZLl6+I/J4cdcRxPEn96/7vaoDnq9HlvSI9SbAGWj4TDhA<BR>
ksyvDB2VBGyfaVPnmPy/4CdjbDFXB5lzF2PezUhChrehKoJXeKXPNqegKV89VAo9<BR>
EH298HuxKO+xZkVMfO9g0kHdFp6VGSCU8Y+ddU2/tMhxHGMCoXOC/sdcuCHl5HRW<BR>
G6cSzXYum2Y1ootALk7U<BR>
=OksF<BR>
-----END PGP SIGNATURE-----<BR>
</SPAN></FONT></FONT></BLOCKQUOTE><FONT SIZE="4"><FONT FACE="Consolas, Courier New, Courier"><SPAN STYLE='font-size:10pt'><BR>
</SPAN></FONT></FONT><FONT COLOR="#808080"><FONT FACE="Arial"><SPAN STYLE='font-size:9pt'>Jean-Francois Laurens<BR>
</SPAN><FONT SIZE="4"><SPAN STYLE='font-size:10pt'>Ingénieur Système Unix<BR>
Resources et Développement<BR>
Secteur Backend<BR>
</SPAN></FONT><SPAN STYLE='font-size:9pt'><B>RTS - Radio Télévision Suisse<BR>
</B>Quai Ernest-Ansermet 20 <BR>
Case postale 234 <BR>
CH - 1211 Genève 8<BR>
T +41 (0)58 236 81 63<BR>
</SPAN></FONT></FONT><FONT SIZE="4"><FONT FACE="Calibri, Verdana, Helvetica, Arial"><SPAN STYLE='font-size:10pt'><BR>
</SPAN></FONT></FONT>
</BODY>
</HTML>