<div dir="ltr">Thank you Dridi.<div>This is very helpful.</div><div><br></div><div>FYI - My apache keepalive is</div><div>KeepAliveTimeout 3<br></div><div><br></div><div>You would suggest increasing this to 5-10 ?</div><div><br></div><div>We had lowered the KeepAliveTimeout as the server is a very busy one and we want to handle many connections.</div><div><br></div></div><br><div class="gmail_quote"><div dir="ltr" class="gmail_attr">On Thu, 15 Apr 2021 at 12:51, Dridi Boukelmoune <dridi@varni.sh> wrote:<br></div><blockquote class="gmail_quote" style="margin:0px 0px 0px 0.8ex;border-left:1px solid rgb(204,204,204);padding-left:1ex">Hello,<br>
<br>
For global timeouts:<br>
<br>
<a href="https://varnish-cache.org/docs/trunk/reference/varnishd.html#run-time-parameters" rel="noreferrer" target="_blank">https://varnish-cache.org/docs/trunk/reference/varnishd.html#run-time-parameters</a><br>
<br>
They contain "timeout" in the name.<br>
<br>
For VCL-defined timeouts:<br>
<br>
<a href="https://varnish-cache.org/docs/trunk/reference/vcl-backend.html#timeout-attributes" rel="noreferrer" target="_blank">https://varnish-cache.org/docs/trunk/reference/vcl-backend.html#timeout-attributes</a><br>
<a href="https://varnish-cache.org/docs/trunk/reference/vcl-probe.html#attribute-timeout" rel="noreferrer" target="_blank">https://varnish-cache.org/docs/trunk/reference/vcl-probe.html#attribute-timeout</a><br>
<a href="https://varnish-cache.org/docs/trunk/reference/vcl-var.html" rel="noreferrer" target="_blank">https://varnish-cache.org/docs/trunk/reference/vcl-var.html</a><br>
<br>
If the problem was a timeout, you would see this in the log:<br>
<br>
    FetchError first byte timeout<br>
<br>
If you are using apache httpd there´s a good chance that incoming<br>
connections are closed after 5s of inactivity by default. But when<br>
varnish pools backend connections, the default backend_idle_timeout is<br>
60s so you may end up reusing a connection that was closed by your<br>
httpd server. You should increase your keep-alive timeout to meet<br>
varnish´s expectations.<br>
<br>
<a href="https://httpd.apache.org/docs/2.4/mod/core.html#keepalivetimeout" rel="noreferrer" target="_blank">https://httpd.apache.org/docs/2.4/mod/core.html#keepalivetimeout</a><br>
<br>
Please note that varnish has a similar timeout_idle that defaults to<br>
5s too. So stacking varnish servers can lead to the same problem if<br>
you rely on the defaults.<br>
<br>
Dridi<br>
<br>
On Thu, Apr 15, 2021 at 6:27 AM Maninder Singh <<a href="mailto:mandys@gmail.com" target="_blank">mandys@gmail.com</a>> wrote:<br>
><br>
> Also, backend is apache 2.4<br>
> and running php-fpm.<br>
><br>
> On Thu, 15 Apr 2021 at 11:52, Maninder Singh <<a href="mailto:mandys@gmail.com" target="_blank">mandys@gmail.com</a>> wrote:<br>
>><br>
>> I have that defined as 2 minutes.<br>
>> backend default {<br>
>>     .host = "127.0.0.1";<br>
>>     .port = "8080";<br>
>>     .first_byte_timeout = 120s;<br>
>> }<br>
>><br>
>> That's why this error is puzzling.<br>
>><br>
>> Any other timeouts ( connect ? ) etc to look at ?<br>
>><br>
>> Also, in the above dump, how much time did it take ?<br>
>><br>
>> To me it looks like it was closed within a second ?<br>
>><br>
>><br>
>> -   BackendOpen    32 reload_2021-04-13T130756.default 127.0.0.1 8080 127.0.0.1 56176<br>
>> -   BackendStart   127.0.0.1 8080<br>
>> -   Timestamp      Bereq: 1618461577.074387 0.281276 0.281276<br>
>> -   FetchError     http first read error: EOF<br>
>> -   BackendClose   32 reload_2021-04-13T130756.default<br>
>> -   Timestamp      Beresp: 1618461577.074430 0.281319 0.000043<br>
>> -   Timestamp      Error: 1618461577.074434 0.281323 0.000004<br>
>><br>
>> On Thu, 15 Apr 2021 at 11:42, Frands Bjerring Hansen <frands.hansen@team.blue> wrote:<br>
>>><br>
>>> Look at the fetch error: http first read error: EOF<br>
>>><br>
>>><br>
>>><br>
>>> Perhaps the backend closed the connection before sending any data or the first_byte_timeout defined for the backend has been reached. The default is 60 seconds.<br>
>>><br>
>>><br>
>>><br>
>>><br>
>>><br>
>>><br>
>>><br>
>>><br>
>>> / Frands Bjerring Hansen<br>
>>> Head of Technology, Linux<br>
>>> Office: +45 70 40 00 00<br>
>>> frands.hansen@team.blue<br>
>>><br>
>>> Operations - Linux<br>
>>> team.blue Denmark A/S<br>
>>> Højvangen 4<br>
>>> 8660 Skanderborg<br>
>>> Denmark<br>
>>> CVR: 29412006<br>
>>><br>
>>><br>
>>><br>
>>><br>
>>> On 15/04/2021, 08.08, "varnish-misc" <varnish-misc-bounces+fbh=<a href="mailto:zitcom.dk@varnish-cache.org" target="_blank">zitcom.dk@varnish-cache.org</a>> wrote:<br>
>>><br>
>>> Hi,<br>
>>><br>
>>> I need some help understanding why the below 503 is happening.<br>
>>><br>
>>><br>
>>><br>
>>> I am logging 503s to a separate file and then querying as below.<br>
>>><br>
>>><br>
>>><br>
>>> varnishlog -q "BerespStatus eq 503" -w /whatever/file<br>
>>><br>
>>> varnishlog -r /whatever/file<br>
>>><br>
>>><br>
>>><br>
>>> What's going wrong here ?<br>
>>><br>
>>> What should I be looking at ?<br>
>>><br>
>>><br>
>>><br>
>>> Please let me know.<br>
>>><br>
>>><br>
>>><br>
>>> *   << BeReq    >> 45926757<br>
>>><br>
>>> -   Begin          bereq 45926756 pass<br>
>>><br>
>>> -   Timestamp      Start: 1618461576.793111 0.000000 0.000000<br>
>>><br>
>>> -   BereqMethod    POST<br>
>>><br>
>>> -   BereqURL       /index.php?&u=85&tr=aa<br>
>>><br>
>>> -   BereqProtocol  HTTP/1.1<br>
>>><br>
>>> -   BereqHeader    X-Forwarded-Proto: https<br>
>>><br>
>>> -   BereqHeader    X-Forwarded-Port: 443<br>
>>><br>
>>> -   BereqHeader    Host: <a href="http://graph.com" rel="noreferrer" target="_blank">graph.com</a> <<a href="http://graph.com" rel="noreferrer" target="_blank">http://graph.com</a>><br>
>>><br>
>>> -   BereqHeader    X-Amzn-Trace-Id: Root=1-xxx<br>
>>><br>
>>> -   BereqHeader    Content-Length: 793<br>
>>><br>
>>> -   BereqHeader    sec-ch-ua: "Google Chrome";v="89", "Chromium";v="89", ";Not A Brand";v="99"<br>
>>><br>
>>> -   BereqHeader    accept: application/json, text/javascript, */*; q=0.01<br>
>>><br>
>>> -   BereqHeader    sec-ch-ua-mobile: ?0<br>
>>><br>
>>> -   BereqHeader    user-agent: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/89.0.4389.128 Safari/537.36<br>
>>><br>
>>> -   BereqHeader    content-type: application/x-www-form-urlencoded; charset=UTF-8<br>
>>><br>
>>> -   BereqHeader    origin: <a href="https://mandy." rel="noreferrer" target="_blank">https://mandy.</a>.com<br>
>>><br>
>>> -   BereqHeader    sec-fetch-site: same-site<br>
>>><br>
>>> -   BereqHeader    sec-fetch-mode: cors<br>
>>><br>
>>> -   BereqHeader    sec-fetch-dest: empty<br>
>>><br>
>>> -   BereqHeader    referer: <a href="https://mandy.com/" rel="noreferrer" target="_blank">https://mandy.com/</a><br>
>>><br>
>>> -   BereqHeader    accept-encoding: gzip, deflate, br<br>
>>><br>
>>> -   BereqHeader    accept-language: en-US,en;q=0.9<br>
>>><br>
>>> -   BereqHeader    X-Forwarded-For: 103.67.157.20, 10.0.0.170<br>
>>><br>
>>> -   BereqHeader    browser: other<br>
>>><br>
>>> -   BereqHeader    serverIp: 10.0.3.237<br>
>>><br>
>>> -   BereqHeader    serverId: abc01<br>
>>><br>
>>> -   BereqHeader    X-Varnish: 45926757<br>
>>><br>
>>> -   VCL_call       BACKEND_FETCH<br>
>>><br>
>>> -   VCL_return     fetch<br>
>>><br>
>>> -   BackendOpen    32 reload_2021-04-13T130756.default 127.0.0.1 8080 127.0.0.1 56176<br>
>>><br>
>>> -   BackendStart   127.0.0.1 8080<br>
>>><br>
>>> -   Timestamp      Bereq: 1618461577.074387 0.281276 0.281276<br>
>>><br>
>>> -   FetchError     http first read error: EOF<br>
>>><br>
>>> -   BackendClose   32 reload_2021-04-13T130756.default<br>
>>><br>
>>> -   Timestamp      Beresp: 1618461577.074430 0.281319 0.000043<br>
>>><br>
>>> -   Timestamp      Error: 1618461577.074434 0.281323 0.000004<br>
>>><br>
>>> -   BerespProtocol HTTP/1.1<br>
>>><br>
>>> -   BerespStatus   503<br>
>>><br>
>>> -   BerespReason   Service Unavailable<br>
>>><br>
>>> -   BerespReason   Backend fetch failed<br>
>>><br>
>>> -   BerespHeader   Date: Thu, 15 Apr 2021 04:39:37 GMT<br>
>>><br>
>>> -   BerespHeader   Server: Varnish<br>
>>><br>
>>> -   VCL_call       BACKEND_ERROR<br>
>>><br>
>>> -   BerespHeader   Content-Type: text/html; charset=utf-8<br>
>>><br>
>>> -   BerespHeader   Retry-After: 5<br>
>>><br>
>>> -   VCL_return     deliver<br>
>>><br>
>>> -   Storage        malloc Transient<br>
>>><br>
>>> -   ObjProtocol    HTTP/1.1<br>
>>><br>
>>> -   ObjStatus      503<br>
>>><br>
>>> -   ObjReason      Backend fetch failed<br>
>>><br>
>>> -   ObjHeader      Date: Thu, 15 Apr 2021 04:39:37 GMT<br>
>>><br>
>>> -   ObjHeader      Server: Varnish<br>
>>><br>
>>> -   ObjHeader      Content-Type: text/html; charset=utf-8<br>
>>><br>
>>> -   ObjHeader      Retry-After: 5<br>
>>><br>
>>> -   Length         1288<br>
>>><br>
>>> -   BereqAcct      948 793 1741 0 0 0<br>
>>><br>
>>> -   End<br>
>>><br>
>>><br>
><br>
> _______________________________________________<br>
> varnish-misc mailing list<br>
> <a href="mailto:varnish-misc@varnish-cache.org" target="_blank">varnish-misc@varnish-cache.org</a><br>
> <a href="https://www.varnish-cache.org/lists/mailman/listinfo/varnish-misc" rel="noreferrer" target="_blank">https://www.varnish-cache.org/lists/mailman/listinfo/varnish-misc</a><br>
</blockquote></div>