<div dir="ltr"><div><div>I'm not as familiar with varnish4 (I need vmods), but in varnish 3, backends need to be specified with timeouts:<br><br>backend backend31 {<br> .host = "10.24.14.112";<br> .port = "80";<br> .probe = backendcheck;<br> .connect_timeout = 3s;<br> .first_byte_timeout = 5s;<br> .between_bytes_timeout = 2s;<br>}<br><br></div>If your backends are averaging 2+ seconds, then your outliers are probably 5-6 seconds... and that could easily trip the defaults (though I don't recall off-hand what they are).<br><br></div>--Jason<br></div><div class="gmail_extra"><br><div class="gmail_quote">On Wed, Mar 11, 2015 at 6:22 AM, Hettwer, Marian <span dir="ltr"><<a href="mailto:mhettwer@team.mobile.de" target="_blank">mhettwer@team.mobile.de</a>></span> wrote:<br><blockquote class="gmail_quote" style="margin:0 0 0 .8ex;border-left:1px #ccc solid;padding-left:1ex">Hi Varnish Users,<br>
<br>
I¹m seeing some weird behavior in a load test I¹m doing. When stressing<br>
our backends up to the area of 2000 req/s, I¹m seeing sporadic 503<br>
responses from varnish.<br>
My understanding is, that this would happen if, for instance, no backend<br>
is available.<br>
<br>
I¹m looking at my logs like that:<br>
varnishlog -n essearchvarnish -q "RespStatus >= 500 or BerespStatus >= 500³<br>
<br>
A sample 503 output is that one:<br>
<br>
* << Request >> 27632438<br>
- Begin req 27630762 rxreq<br>
- Timestamp Start: 1426066874.412913 0.000000 0.000000<br>
- Timestamp Req: 1426066874.412913 0.000000 0.000000<br>
- ReqStart 10.47.28.251 49641<br>
- ReqMethod GET<br>
- ReqURL /svc/somequery?string?documents=1<br>
- ReqProtocol HTTP/1.1<br>
- ReqHeader Accept-Language: de<br>
- ReqHeader User-Agent: Java1.8.0<br>
- ReqHeader Host: essearch.local<br>
- ReqHeader Connection: Keep-Alive<br>
- ReqHeader Accept-Encoding: gzip<br>
- VCL_call RECV<br>
- VCL_return hash<br>
- VCL_call HASH<br>
- VCL_return lookup<br>
- Debug "XXXX HIT-FOR-PASS"<br>
- HitPass 2201620563<br>
- VCL_call PASS<br>
- VCL_return fetch<br>
- Link bereq 27632439 pass<br>
- Timestamp Fetch: 1426066874.412967 0.000054 0.000054<br>
- Timestamp Process: 1426066874.412979 0.000066 0.000012<br>
- RespHeader Date: Wed, 11 Mar 2015 09:41:14 GMT<br>
- RespHeader Server: Varnish<br>
- RespHeader X-Varnish: 27632438<br>
- RespProtocol HTTP/1.1<br>
- RespStatus 503<br>
- RespReason Service Unavailable<br>
- RespReason Service Unavailable<br>
- VCL_call SYNTH<br>
- RespHeader Content-Type: text/html; charset=utf-8<br>
- RespHeader Retry-After: 5<br>
- VCL_return deliver<br>
- RespHeader Content-Length: 282<br>
- Debug "RES_MODE 2"<br>
- RespHeader Connection: keep-alive<br>
- Timestamp Resp: 1426066874.413033 0.000119 0.000053<br>
- ReqAcct 454 0 454 212 282 494<br>
- End<br>
<br>
<br>
<br>
What makes me wonder is, that this output is missing the actual backend<br>
request attempts. Also, printing "RespReason Service Unavailable³ twice in<br>
a row?!? Why?<br>
So in a second shell, on the same varnish at the same time, I have this<br>
query running:<br>
<br>
varnishlog -b -n essearchvarnish -q "RespStatus >= 500 or BerespStatus >=<br>
500³<br>
I added the -b parameter to see the backend requests.<br>
However, I get no output at all. So it seems varnish would throw the 503<br>
without asking the backend?<br>
<br>
Or, hopefully more likely, I¹m not using varnishlog correctly?!<br>
<br>
This is varnish 4.0.3-2~wheezy. How can I print client and backend<br>
connections in one go?<br>
Doing using the -c and -b parameter in parallel doesn¹t produce any output<br>
(while in my other console, I still have the first query which produces<br>
the above output).<br>
<br>
I know that around 2000 req/s my backends are getting a bit slower ( up to<br>
2 seconds for responses), but this should not hit any internal timeouts of<br>
varnish, right? I haven¹t changed the default timeouts.<br>
Also the backends itself are healthy. I¹m watching the backends (several<br>
tomcats) directly, and also from the varnish perspective via<br>
watch -n1 varnishadm -n essearchvarnish backend.list<br>
Everything looks healthy.<br>
<br>
<br>
Any help for how I could dig into this further would be appreciated :-)<br>
I guess it boils down to better use varnishlog on my side. Like getting<br>
client and backend connections for a request at the same time and not by<br>
using varnishlog in two shells differently.<br>
<br>
best regards,<br>
Marian<br>
<br>
<br>
_______________________________________________<br>
varnish-misc mailing list<br>
<a href="mailto:varnish-misc@varnish-cache.org">varnish-misc@varnish-cache.org</a><br>
<a href="https://www.varnish-cache.org/lists/mailman/listinfo/varnish-misc" target="_blank">https://www.varnish-cache.org/lists/mailman/listinfo/varnish-misc</a><br>
</blockquote></div><br></div>