Re: Random “http first read error: EOF” errors

Hazar Güney hazarguney at gmail.com
Sat Apr 1 13:14:44 CEST 2017


We see this error a few times in a day on a highly busy production
environment. Unfortunately there is too much traffic on the server to keep
tcpdump/ngrep running and we cannot re-produce it on test environment :(

I have started tcpdump on a test environment of another implementation and
will let you as soon as the issue gets triggerred again.

On Fri, Mar 31, 2017 at 4:17 PM, Andrei <lagged at gmail.com> wrote:

> Can you provide a tcpdump/ngrep of the requests between
> Client/Varnish/Apache along with the varnishlog entry to see if that
> uncovers anything?
>
> On Fri, Mar 31, 2017 at 7:25 AM, Hazar Güney <hazarguney at gmail.com> wrote:
>
>> Any idea?
>>
>> On Thu, Mar 30, 2017 at 3:41 PM, Hazar Güney <hazarguney at gmail.com>
>> wrote:
>>
>>> It did not work either:
>>>
>>>     *   << BeReq    >> 127418176
>>>     -   Begin          bereq 127418175 fetch
>>>     -   Timestamp      Start: 1490877149.450124 0.000000 0.000000
>>>     -   BereqMethod    GET
>>>     -   BereqURL       XXXX
>>>     -   BereqProtocol  HTTP/1.1
>>>     -   BereqHeader    Accept: text/css,*/*;q=0.1
>>>     -   BereqHeader    User-Agent: Mozilla/5.0 (iPhone; CPU iPhone OS
>>> 10_2 like Mac OS X) AppleWebKit/602.3.12 (KHTML, like Gecko) Version/10.0
>>> Mobile/14C92 Safari/602.1
>>>     -   BereqHeader    Accept-Language: tr-tr
>>>     -   BereqHeader    Referer: XXXX
>>>     -   BereqHeader    Host: XXXX
>>>     -   BereqHeader    RIP: XXXX
>>>     -   BereqHeader    X-Forwarded-For: XXXX
>>>     -   BereqHeader    Accept-Encoding: gzip
>>>     -   BereqHeader    X-Varnish: 127418176
>>>     -   VCL_call       BACKEND_FETCH
>>>     -   BereqHeader    connection: Close
>>>     -   VCL_return     fetch
>>>     -   BackendOpen    25 reload_2017-03-30T14:53:46.st2 10.35.78.11 80
>>> 172.17.0.2 59152
>>>     -   BackendStart   10.35.78.11 80
>>>     -   Timestamp      Bereq: 1490877149.450594 0.000470 0.000470
>>>     -   FetchError     http first read error: EOF
>>>     -   BackendClose   25 reload_2017-03-30T14:53:46.st2
>>>     -   Timestamp      Beresp: 1490877149.451184 0.001060 0.000590
>>>     -   Timestamp      Error: 1490877149.451189 0.001065 0.000005
>>>     -   BerespProtocol HTTP/1.1
>>>     -   BerespStatus   503
>>>     -   BerespReason   Service Unavailable
>>>     -   BerespReason   Backend fetch failed
>>>     -   BerespHeader   Date: Thu, 30 Mar 2017 12:32:29 GMT
>>>     -   BerespHeader   Server: Varnish
>>>     -   VCL_call       BACKEND_ERROR
>>>     -   BereqHeader    X-Varnish-Backend-5xx: 1
>>>     -   VCL_return     retry
>>>     -   Timestamp      Retry: 1490877149.451205 0.001081 0.000016
>>>     -   Link           bereq 127298071 retry
>>>     -   End
>>>
>>> On Thu, Mar 30, 2017 at 2:34 PM, Guillaume Quintard <
>>> guillaume at varnish-software.com> wrote:
>>>
>>>> It does, I'm suspecting that the connection reuse is creating some
>>>> issues, probably because Apache is doing some non-standard stuff (protip:
>>>> always blame Apache).
>>>>
>>>> --
>>>> Guillaume Quintard
>>>>
>>>> On Thu, Mar 30, 2017 at 1:17 PM, Hazar Güney <hazarguney at gmail.com>
>>>> wrote:
>>>>
>>>>> "Connection: close" supersedes keep-alive behavior, is that correct?
>>>>>
>>>>> On Thu, Mar 30, 2017 at 2:08 PM, Guillaume Quintard <
>>>>> guillaume at varnish-software.com> wrote:
>>>>>
>>>>>> Can you try something: add 'set bereq.http.connection = "Close"; ' at
>>>>>> the beginning of vcl_backend_fetch and see if that helps?
>>>>>>
>>>>>> --
>>>>>> Guillaume Quintard
>>>>>>
>>>>>> On Thu, Mar 30, 2017 at 1:04 PM, Hazar Güney <hazarguney at gmail.com>
>>>>>> wrote:
>>>>>>
>>>>>>> MaxKeepAliveRequests 20
>>>>>>> KeepAliveTimeout 2
>>>>>>>
>>>>>>> Version is "4.1.3 revision 5e3b6d2". We have also seen "straight
>>>>>>> insufficient bytes" error with POST requests to a specific php script
>>>>>>> hosted by another backend and fixed it by using "pipe" instead of "pass"
>>>>>>> but this specific backend gives "http first read error: EOF" error. Another
>>>>>>> example from today:
>>>>>>>
>>>>>>> *   << BeReq    >> 126635444
>>>>>>> -   Begin          bereq 126635443 fetch
>>>>>>> -   Timestamp      Start: 1490870598.921499 0.000000 0.000000
>>>>>>> -   BereqMethod    GET
>>>>>>> -   BereqURL       XXXX
>>>>>>> -   BereqProtocol  HTTP/1.1
>>>>>>> -   BereqHeader    Host: XXXX
>>>>>>> -   BereqHeader    User-Agent: Mozilla/5.0 (Windows NT 10.0; Win64;
>>>>>>> x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/56.0.2924.87
>>>>>>> Safari/537.36
>>>>>>> -   BereqHeader    Accept: image/webp,image/*,*/*;q=0.8
>>>>>>> -   BereqHeader    Referer: XXXX
>>>>>>> -   BereqHeader    Accept-Language: tr-TR,tr;q=0.8,en-US;q=0.6,en;
>>>>>>> q=0.4
>>>>>>> -   BereqHeader    RIP: XXXX
>>>>>>> -   BereqHeader    X-Forwarded-For: XXXX
>>>>>>> -   BereqHeader    Accept-Encoding: gzip
>>>>>>> -   BereqHeader    X-Varnish: 126635444
>>>>>>> -   VCL_call       BACKEND_FETCH
>>>>>>> -   VCL_return     fetch
>>>>>>> -   BackendOpen    35 reload_2017-03-20T11:32:44.st2 10.35.78.11 80
>>>>>>> 172.17.0.2 48896
>>>>>>> -   BackendStart   10.35.78.11 80
>>>>>>> -   Timestamp      Bereq: 1490870598.922050 0.000552 0.000552
>>>>>>> *-   FetchError     http first read error: EOF*
>>>>>>> -   BackendClose   35 reload_2017-03-20T11:32:44.st2
>>>>>>> -   Timestamp      Beresp: 1490870598.922622 0.001124 0.000572
>>>>>>> -   Timestamp      Error: 1490870598.922627 0.001129 0.000005
>>>>>>> -   BerespProtocol HTTP/1.1
>>>>>>> -   BerespStatus   503
>>>>>>> -   BerespReason   Service Unavailable
>>>>>>> -   BerespReason   Backend fetch failed
>>>>>>> -   BerespHeader   Date: Thu, 30 Mar 2017 10:43:18 GMT
>>>>>>> -   BerespHeader   Server: Varnish
>>>>>>> -   VCL_call       BACKEND_ERROR
>>>>>>> -   BereqHeader    X-Varnish-Backend-5xx: 1
>>>>>>> -   VCL_return     retry
>>>>>>> -   Timestamp      Retry: 1490870598.922657 0.001159 0.000030
>>>>>>> -   Link           bereq 126832283 retry
>>>>>>> -   End
>>>>>>>
>>>>>>> On Wed, Mar 29, 2017 at 12:03 PM, Mattias Geniar <mattias at nucleus.be
>>>>>>> > wrote:
>>>>>>>
>>>>>>>> > Backend is Apache.
>>>>>>>>
>>>>>>>> In older Varnish versions, you could sometimes see a similar error;
>>>>>>>>
>>>>>>>> >   11 FetchError   c straight insufficient bytes
>>>>>>>>
>>>>>>>> The error message you’re seeing might be related, as it mentions
>>>>>>>> the EOF.
>>>>>>>>
>>>>>>>> This happens when the backend sends a Content-Length header that
>>>>>>>> doesn’t match the _actual_ content length it’s sending. In Apache, this was
>>>>>>>> commonly caused by a mod_deflate misconfiguration.
>>>>>>>>
>>>>>>>> For testing, could you try disabling Gzip either in your backend or
>>>>>>>> strip the Accept-Encoding header in Varnish to force a plain text response?
>>>>>>>>
>>>>>>>> Mattias
>>>>>>>>
>>>>>>>>
>>>>>>>
>>>>>>
>>>>>
>>>>
>>>
>>
>> _______________________________________________
>> varnish-misc mailing list
>> varnish-misc at varnish-cache.org
>> https://www.varnish-cache.org/lists/mailman/listinfo/varnish-misc
>>
>
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <https://www.varnish-cache.org/lists/pipermail/varnish-misc/attachments/20170401/a2ec06dd/attachment.html>


More information about the varnish-misc mailing list