Hit idle send timeout

Guillaume Quintard guillaume at varnish-software.com
Mon Sep 25 07:21:41 UTC 2017


63504 is the total size (headers+body), and 55480 is what could be pushed
to the kernel. You don't really know if it was really sent (or received,
for that matter).

-- 
Guillaume Quintard

On Sep 25, 2017 07:29, "Andrei" <lagged at gmail.com> wrote:

Hi Guillaume,

Thanks for the update! :)
Am I reading the log wrong, or is there a difference in Content-Length (
63072), and the debug data which to me suggests it's expecting to send
63504 and only got as far as 55480?

On Sun, Sep 24, 2017 at 11:36 AM, Guillaume Quintard <
guillaume at varnish-software.com> wrote:

> You client dropped the connection, not much you can do or worry about.
>
> --
> Guillaume Quintard
>
> On Sat, Sep 2, 2017 at 10:15 PM, Andrei <lagged at gmail.com> wrote:
>
>> Hello everyone,
>>
>> I'm running 4.1.8 as a frontend to a local Apache 2.4 and just recently
>> ran into a burst of the following "idle/write errors" without any
>> corresponding errors logged in Apache. Any suggestions on what to keep an
>> eye on or further review would be greatly appreciated.
>>
>> *   << Request  >> 482784125
>> -   Begin          req 482784124 rxreq
>> -   Timestamp      Start: 1504382885.868717 0.000000 0.000000
>> -   Timestamp      Req: 1504382885.868717 0.000000 0.000000
>> -   ReqStart       [redacted.xfwd2IP] 35207
>> -   ReqMethod      GET
>> -   ReqURL         /[redacted.url]/
>> -   ReqProtocol    HTTP/1.1
>> -   ReqHeader      Host: www.[redacted.domain.tld]
>> -   ReqHeader      User-Agent: Mozilla/5.0 (Linux; Android 7.0; SM-G920F
>> Build/NRD90M) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/60.0.3112.116
>> Mobile Safari/537.36
>> -   ReqHeader      Accept: text/html,application/xhtml+xm
>> l,application/xml;q=0.9,image/webp,image/apng,*/*;q=0.8
>> -   ReqHeader      Accept-Language: ro-RO,ro;q=0.8,en-US;q=0.6,en;q=0.4
>> -   ReqHeader      Cf-Connecting-Ip: [redacted.xfwd1IP]
>> -   ReqHeader      Cf-Ipcountry: RO
>> -   ReqHeader      Cf-Origin-Https: off
>> -   ReqHeader      Cf-Ray: 3983196ce0b87ea0-BUD
>> -   ReqHeader      Cf-Visitor: {"scheme":"http"}
>> -   ReqHeader      Cookie: __cfduid=da15bbd5734efa927910bae7091f5c3c81501871885;
>> __PPU_SESSION_1_1335313_false=1504207577718|3|1504207684422|3|1;
>> _ga=GA1.2.606320764.1502399957; __atuvc=2%7C32%2C0%7C33%2C4%7C
>> 34%2C11%7C35
>> -   ReqHeader      Referer: https://www.google.ro/
>> -   ReqHeader      Upgrade-Insecure-Requests: 1
>> -   ReqHeader      X-Forwarded-For: [redacted.xfwd1IP]
>> -   ReqHeader      X-Forwarded-Proto: http
>> -   ReqHeader      Accept-Encoding: gzip
>> -   ReqHeader      Connection: close
>> -   ReqUnset       X-Forwarded-For: [redacted.xfwd1IP]
>> -   ReqHeader      X-Forwarded-For: [redacted.xfwd1IP], [redacted.xfwd2IP]
>> -   VCL_call       RECV
>> -   VCL_acl        MATCH cloudflare "172.64.0.0/13"
>> -   ReqHeader      X-Country: RO
>> -   ReqHeader      ignore_becache: 1
>> -   ReqUnset       Host: www.[redacted.domain.tld]
>> -   ReqHeader      Host: www.[redacted.domain.tld]
>> -   ReqUnset       X-Forwarded-For: [redacted.xfwd1IP], [redacted.xfwd2IP]
>> -   ReqHeader      X-Forwarded-For-Src: CloudFlare
>> -   ReqHeader      X-Real-IP: [redacted.xfwd1IP]
>> -   ReqHeader      X-Forwarded-For: [redacted.xfwd1IP]
>> -   ReqHeader      X-Client: [redacted.xfwd2IP]
>> -   VCL_acl        NO_MATCH facebook
>> -   ReqUnset       X-Forwarded-Proto: http
>> -   ReqHeader      X-Forwarded-Proto: http
>> -   ReqHeader      X-Forwarded-HTTPS: off
>> -   ReqHeader      X-Port: 80
>> -   ReqHeader      X-Forwarded-Port: 80
>> -   ReqHeader      X-HTTPS: off
>> -   VCL_acl        NO_MATCH global_blacklist
>> -   VCL_acl        NO_MATCH tor_blacklist
>> -   ReqHeader      X-UA-Device: pc
>> -   ReqUnset       X-UA-Device: pc
>> -   ReqHeader      X-UA-Device: mobile-android
>> -   ReqHeader      X-My-Purge-Key: [redacted]
>> -   ReqHeader      X-Purge-Key-Auth: false
>> -   ReqURL         /[redacted.url]/
>> -   VCL_Log        COOKIESTRIP:/[redacted.url]/
>> -   ReqUnset       Cookie: __cfduid=da15bbd5734efa927910bae7091f5c3c81501871885;
>> __PPU_SESSION_1_1335313_false=1504207577718|3|1504207684422|3|1;
>> _ga=GA1.2.606320764.1502399957; __atuvc=2%7C32%2C0%7C33%2C4%7C
>> 34%2C11%7C35
>> -   ReqHeader      allow_override: enabled
>> -   ReqUnset       Accept-Encoding: gzip
>> -   ReqHeader      Accept-Encoding: gzip
>> -   ReqHeader      Surrogate-Capability: key=ESI/1.0
>> -   ReqUnset       X-My-Purge-Key: [redacted]
>> -   ReqHeader      X-TTL: 14400.000
>> -   ReqHeader      X-Cacheable: YES:Dynamic cache, ttl: 14400.000
>> -   ReqHeader      X-Req-Type: Cache:Dynamic
>> -   VCL_return     hash
>> -   VCL_call       HASH
>> -   ReqHeader      hash: /[redacted.url]/
>> -   ReqUnset       hash: /[redacted.url]/
>> -   ReqHeader      hash: www.[redacted.domain.tld]#/[redacted.url]/
>> -   ReqUnset       hash: www.[redacted.domain.tld]#/[redacted.url]/
>> -   ReqHeader      hash: http#mobile-android#www.[redac
>> ted.domain.tld]#/[redacted.url]/
>> -   VCL_return     lookup
>> -   Hit            482125483
>> -   VCL_call       HIT
>> -   VCL_Log        OKHITDELIVER: obj.ttl:14065.370 obj.keep: 0.000
>> obj.grace: 21600.000
>> -   VCL_return     deliver
>> -   RespProtocol   HTTP/1.1
>> -   RespStatus     200
>> -   RespReason     OK
>> -   RespHeader     Date: Sat, 02 Sep 2017 20:02:30 GMT
>> -   RespHeader     x-frame-options: SAMEORIGIN
>> -   RespHeader     X-XSS-Protection: 1; mode=block
>> -   RespHeader     X-Content-Type-Options: nosniff
>> -   RespHeader     X-Pingback: http://www.[redacted.domain.tl
>> d]/xmlrpc.php
>> -   RespHeader     Link: <http://www.[redacted.domain.tld]/?p=2710>;
>> rel=shortlink
>> -   RespHeader     Content-Type: text/html; charset=UTF-8
>> -   RespHeader     X-Req-Type: Cache:Dynamic
>> -   RespHeader     Accept-Encoding: gzip
>> -   RespHeader     Vary: Accept-Encoding, X-UA-Device
>> -   RespHeader     X-UA-Device: mobile-android
>> -   RespHeader     X-Req-Host: www.[redacted.domain.tld]
>> -   RespHeader     X-Req-URL: /[redacted.url]/
>> -   RespHeader     X-Req-URL-Base: /[redacted.url]/
>> -   RespHeader     X-TTL: 14400.000
>> -   RespHeader     X-Cacheable: YES:Cacheable dynamic, ttl: 14400.000
>> -   RespHeader     X-Varnish: 482784125 482125483
>> -   RespHeader     Age: 334
>> -   RespHeader     Via: 1.1 varnish-v4
>> -   VCL_call       DELIVER
>> -   RespHeader     X-Cache: HIT
>> -   VCL_Log        OKHITDELIVERY: obj.hits: 1 ttl:14400.000
>> -   RespUnset      X-Req-Type: Cache:Dynamic
>> -   RespUnset      Age: 334
>> -   RespUnset      X-Cache: HIT
>> -   RespUnset      X-Cacheable: YES:Cacheable dynamic, ttl: 14400.000
>> -   RespUnset      X-TTL: 14400.000
>> -   RespUnset      X-Req-Host: www.[redacted.domain.tld]
>> -   RespUnset      X-Req-URL: /[redacted.url]/
>> -   RespUnset      X-Req-URL-Base: /[redacted.url]/
>> -   RespUnset      X-Varnish: 482784125 482125483
>> -   RespUnset      Via: 1.1 varnish-v4
>> -   RespUnset      X-UA-Device: mobile-android
>> -   VCL_return     deliver
>> -   Timestamp      Process: 1504382885.868905 0.000188 0.000188
>> -   RespHeader     Accept-Ranges: bytes
>> -   RespHeader     Content-Length: 63072
>> -   Debug          "RES_MODE 2"
>> -   RespHeader     Connection: close
>> -   Debug          "Hit idle send timeout, wrote = 55480/63504; retrying"
>> -   Debug          "Write error, retval = -1, len = 8024, errno = Broken
>> pipe"
>> -   Timestamp      Resp: 1504382886.049021 0.180304 0.180115
>> -   ReqAcct        869 0 869 432 63072 63504
>> -   End
>>
>>
>> _______________________________________________
>> 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/20170925/b2195d3d/attachment.html>


More information about the varnish-misc mailing list