Mailing List Archive: "http first read error: EOF" errors from WordPress backend

"http first read error: EOF" errors from WordPress backend

Mar 30, 2017, 11:25 PM

Post #1 of 4 (418 views)

Hello,

From a backend with Apache+WordPress, we occasionally see "http first read
error: EOF" errors. This situation is different then my first question
because this time it seems that Varnish waits for 60 seconds from backend.
According to Apache access log, backend responds to the request from
Varnish less than 1 second which is very strange.

(We are 3 hours ahead of GMT)

*Backend:*

[31/Mar/2017:02:25:29 +0300] "GET XXXX HTTP/1.1" 200 22575

*Varnish:*

* << BeReq >> 3684412
- Begin bereq 3684411 fetch
- Timestamp Start: 1490916329.664410 0.000000 0.000000
- BereqMethod GET
- BereqURL XXXX
- BereqProtocol HTTP/1.1
- BereqHeader Host: XXXX
- BereqHeader Accept:
text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8
- BereqHeader From: googlebot(at)googlebot.com
- BereqHeader User-Agent: Mozilla/5.0 (Linux; Android 6.0.1; Nexus 5X
Build/MMB29P) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/41.0.2272.96
Mobile Safari/537.36 (compatible; Googlebot/2.1; +
http://www.google.com/bot.html)
- BereqHeader RIP: 66.249.66.227
- BereqHeader X-Forwarded-For: XXXX
- BereqHeader Accept-Encoding: gzip
- BereqHeader X-Varnish: 3684412
- VCL_call BACKEND_FETCH
- VCL_return fetch
- BackendOpen 21 reload_2017-03-21T100643.default 10.35.78.153 80
172.17.0.2 56104
- BackendStart XXXX 80
- Timestamp Bereq: 1490916329.664853 0.000443 0.000443
*- FetchError http first read error: EOF*
- BackendClose 21 reload_2017-03-21T100643.default
- Timestamp Beresp: 1490916389.664967 *60.000557* 60.000114
- Timestamp Error: 1490916389.664978 *60.000567 *0.000011
- BerespProtocol HTTP/1.1
- BerespStatus 503
- BerespReason Service Unavailable
- BerespReason Backend fetch failed
- BerespHeader Date: Thu, 30 Mar 2017 23:26:29 GMT
- BerespHeader Server: Varnish
- VCL_call BACKEND_ERROR
- BerespHeader Content-Type: text/html; charset=utf-8
- BerespHeader Retry-After: 5
- VCL_return deliver
- Storage malloc Transient
- ObjProtocol HTTP/1.1
- ObjStatus 503
- ObjReason Backend fetch failed
- ObjHeader Date: Thu, 30 Mar 2017 23:26:29 GMT
- ObjHeader Server: Varnish
- ObjHeader Content-Type: text/html; charset=utf-8
- ObjHeader Retry-After: 5
- Length 284
- BereqAcct 509 0 509 0 0 0
- End

* << Request >> 3684411
- Begin req 3684410 rxreq
- Timestamp Start: 1490916329.664345 0.000000 0.000000
- Timestamp Req: 1490916329.664345 0.000000 0.000000
- ReqStart XXXX 45415
- ReqMethod GET
- ReqURL XXXX
- ReqProtocol HTTP/1.1
- ReqHeader Host: XXXX
- ReqHeader Connection: Keep-alive
- ReqHeader Accept:
text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8
- ReqHeader From: googlebot(at)googlebot.com
- ReqHeader User-Agent: Mozilla/5.0 (Linux; Android 6.0.1; Nexus 5X
Build/MMB29P) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/41.0.2272.96
Mobile Safari/537.36 (compatible; Googlebot/2.1; +
http://www.google.com/bot.html)
- ReqHeader RIP: 66.249.66.227
- ReqHeader X-Forwarded-For: XXXX
- VCL_call RECV
- VCL_return hash
- VCL_call HASH
- VCL_return lookup
- VCL_call MISS
- VCL_return fetch
- Link bereq 3684412 fetch
- Timestamp Fetch: 1490916389.665129 60.000784 60.000784
- RespProtocol HTTP/1.1
- RespStatus 503
- RespReason Backend fetch failed
- RespHeader Date: Thu, 30 Mar 2017 23:26:29 GMT
- RespHeader Server: Varnish
- RespHeader Content-Type: text/html; charset=utf-8
- RespHeader Retry-After: 5
- RespHeader X-Varnish: 3684411
- RespHeader Age: 0
- RespHeader Via: 1.1 varnish-v4
- VCL_call DELIVER
- VCL_acl NO_MATCH hitpass
- RespUnset Via: 1.1 varnish-v4
- RespUnset X-Varnish: 3684411
- VCL_return deliver
- Timestamp Process: 1490916389.665181 60.000836 0.000052
- RespHeader Content-Length: 284
- Debug "RES_MODE 2"
- RespHeader Connection: keep-alive
- Timestamp Resp: 1490916389.665241 60.000896 0.000060
- ReqAcct 461 0 461 200 284 484
- End

Re: "http first read error: EOF" errors from WordPress backend [ In reply to ]

mattias at nucleus

Mar 31, 2017, 1:11 AM

Post #2 of 4 (417 views)

Permalink

> - FetchError http first read error: EOF
> - BackendClose 21 reload_2017-03-21T100643.default
> - Timestamp Beresp: 1490916389.664967 60.000557 60.000114
> - Timestamp Error: 1490916389.664978 60.000567 0.000011

At the risk of repeating myself: try to disable gzip & any wordpress plugins that might be trying to gzip on their own (aka: output buffering in PHP).

To me, this seems like Varnish is waiting for the backend to send more data, because it replied with a certain Content-Length header but sent a few bytes less than it advertised, and Varnish is waiting for those missing bytes.

Mattias

_______________________________________________
varnish-misc mailing list
varnish-misc@varnish-cache.org
https://www.varnish-cache.org/lists/mailman/listinfo/varnish-misc

Re: "http first read error: EOF" errors from WordPress backend [ In reply to ]

hazarguney at gmail

Mar 31, 2017, 5:31 AM

Post #3 of 4 (416 views)

Permalink

But "Content-Length" header is not available at all. I'm afraid we cannot
keep gzip disabled even if it solves the issue, Varnish has to be able to
handle gzipped inputs from the backend.

On Fri, Mar 31, 2017 at 11:11 AM, Mattias Geniar <mattias@nucleus.be> wrote:

> > - FetchError http first read error: EOF
> > - BackendClose 21 reload_2017-03-21T100643.default
> > - Timestamp Beresp: 1490916389.664967 60.000557 60.000114
> > - Timestamp Error: 1490916389.664978 60.000567 0.000011
>
> At the risk of repeating myself: try to disable gzip & any wordpress
> plugins that might be trying to gzip on their own (aka: output buffering in
> PHP).
>
> To me, this seems like Varnish is waiting for the backend to send more
> data, because it replied with a certain Content-Length header but sent a
> few bytes less than it advertised, and Varnish is waiting for those missing
> bytes.
>
> Mattias
>
>

Re: "http first read error: EOF" errors from WordPress backend [ In reply to ]

guillaume at varnish-software

Apr 12, 2017, 2:00 AM

Post #4 of 4 (406 views)

Permalink

Can you try and report? It may be a bug on either side, deactivating
temporarily could confirm that it's indeed a gzip problem.

--
Guillaume Quintard

On Fri, Mar 31, 2017 at 2:31 PM, Hazar Güney <hazarguney@gmail.com> wrote:

> But "Content-Length" header is not available at all. I'm afraid we cannot
> keep gzip disabled even if it solves the issue, Varnish has to be able to
> handle gzipped inputs from the backend.
>
> On Fri, Mar 31, 2017 at 11:11 AM, Mattias Geniar <mattias@nucleus.be>
> wrote:
>
>> > - FetchError http first read error: EOF
>> > - BackendClose 21 reload_2017-03-21T100643.default
>> > - Timestamp Beresp: 1490916389.664967 60.000557 60.000114
>> > - Timestamp Error: 1490916389.664978 60.000567 0.000011
>>
>> At the risk of repeating myself: try to disable gzip & any wordpress
>> plugins that might be trying to gzip on their own (aka: output buffering in
>> PHP).
>>
>> To me, this seems like Varnish is waiting for the backend to send more
>> data, because it replied with a certain Content-Length header but sent a
>> few bytes less than it advertised, and Varnish is waiting for those missing
>> bytes.
>>
>> Mattias
>>
>>
>
> _______________________________________________
> varnish-misc mailing list
> varnish-misc@varnish-cache.org
> https://www.varnish-cache.org/lists/mailman/listinfo/varnish-misc
>