[squid-users] squid cache peer issues

[Amos Jeffries]

On 21/12/2015 2:00 p.m., Alex Samad wrote:
> Hi
> 
> running on centos 6.7
> 
> 3.5.12 still not available on centos 6.
> 
> rpm -qa | grep squid
> squid-helpers-3.5.11-1.el6.x86_64
> squid-3.5.11-1.el6.x86_64
> 
> This is the 2 cache_peer statements I use
> 
> # on alcdmz1
> cache_peer gsdmz1.yieldbroker.com sibling 3128 4827 proxy-only htcp
> no-query standby=10
> #cache_peer alcdmz1.yieldbroker.com sibling 3128 4827 proxy-only htcp
> no-query standby=10
> 
> # on gsdmz1
> #cache_peer gsdmz1.yieldbroker.com sibling 3128 4827 proxy-only htcp
> no-query standby=10
> cache_peer alcdmz1.yieldbroker.com sibling 3128 4827 proxy-only htcp
> no-query standby=10
> 
> on alcdmz1 with export http_proxy pointing to alcdmz1
> 
> wget -d  http://fonts.gstatic.com/s/lato/v11/H2DMvhDLycM56KNuAtbJYA.woff2
> -O /dev/null
> Setting --output-document (outputdocument) to /dev/null
> DEBUG output created by Wget 1.12 on linux-gnu.
> 
> --2015-12-21 11:58:05--
> http://fonts.gstatic.com/s/lato/v11/H2DMvhDLycM56KNuAtbJYA.woff2
> Resolving alcdmz1... 10.32.20.111
> Caching alcdmz1 => 10.32.20.111
> Connecting to alcdmz1|10.32.20.111|:3128... connected.
> Created socket 4.
> Releasing 0x000000000101d540 (new refcount 1).
> 
> ---request begin---
> GET http://fonts.gstatic.com/s/lato/v11/H2DMvhDLycM56KNuAtbJYA.woff2 HTTP/1.0
> User-Agent: Wget/1.12 (linux-gnu)
> Accept: */*
> Host: fonts.gstatic.com
> 
> ---request end---
> Proxy request sent, awaiting response...
> ---response begin---
> HTTP/1.1 200 OK
> Content-Type: font/woff2
> Access-Control-Allow-Origin: *
> Timing-Allow-Origin: *
> Date: Mon, 30 Nov 2015 04:06:16 GMT
> Expires: Tue, 29 Nov 2016 04:06:16 GMT
> Last-Modified: Mon, 06 Oct 2014 20:40:59 GMT
> X-Content-Type-Options: nosniff
> Server: sffe
> Content-Length: 25604
> X-XSS-Protection: 1; mode=block
> Cache-Control: public, max-age=31536000
> Age: 1803109
> Warning: 113 alcdmz1 (squid) This cache hit is still fresh and more
> than 1 day old
> X-Cache: HIT from alcdmz1
> X-Cache-Lookup: HIT from alcdmz1:3128
> Via: 1.1 alcdmz1 (squid)
> Connection: close
> 
> ---response end---
> 200 OK
> Length: 25604 (25K) [font/woff2]
> Saving to: `/dev/null'
> 
> 100%[==============================================================================================>]
> 25,604      --.-K/s   in 0s
> 
> Closed fd 4
> 2015-12-21 11:58:05 (1.01 GB/s) - `/dev/null' saved [25604/25604]
> 
> 
> on gsdmz1
> 
> 
> wget -d  http://fonts.gstatic.com/s/lato/v11/H2DMvhDLycM56KNuAtbJYA.woff2
> -O /dev/null
> Setting --output-document (outputdocument) to /dev/null
> DEBUG output created by Wget 1.12 on linux-gnu.
> 
> --2015-12-21 11:58:59--
> http://fonts.gstatic.com/s/lato/v11/H2DMvhDLycM56KNuAtbJYA.woff2
> Resolving gsdmz1... 10.32.20.110
> Caching gsdmz1 => 10.32.20.110
> Connecting to gsdmz1|10.32.20.110|:3128... connected.
> Created socket 4.
> Releasing 0x00000000010a2930 (new refcount 1).
> 
> ---request begin---
> GET http://fonts.gstatic.com/s/lato/v11/H2DMvhDLycM56KNuAtbJYA.woff2 HTTP/1.0
> User-Agent: Wget/1.12 (linux-gnu)
> Accept: */*
> Host: fonts.gstatic.com
> 
> ---request end---
> Proxy request sent, awaiting response...
> ---response begin---
> HTTP/1.1 504 Gateway Timeout
> Server: squid
> Mime-Version: 1.0
> Date: Mon, 21 Dec 2015 00:58:59 GMT
> Content-Type: text/html;charset=utf-8
> Content-Length: 3964
> X-Squid-Error: ERR_ONLY_IF_CACHED_MISS 0
> Vary: Accept-Language
> Content-Language: en
> Age: 1450659540
> Warning: 113 alcdmz1 (squid) This cache hit is still fresh and more
> than 1 day old
> Warning: 110 squid "Response is stale"
> Warning: 111 squid "Revalidation failed"
> X-Cache: HIT from alcdmz1
> X-Cache-Lookup: HIT from alcdmz1:3128
> X-Cache: MISS from gsdmz1
> X-Cache-Lookup: MISS from gsdmz1:3128
> Via: 1.1 alcdmz1 (squid), 1.1 gsdmz1 (squid)
> Connection: close
> 
> ---response end---
> 504 Gateway Timeout
> Closed fd 4
> 2015-12-21 11:58:59 ERROR 504: Gateway Timeout.
> 
> 
> so why does it work from alc and not from gs ???

The alc fetch is going:
  client->alc->Internet/parent

The gs fetch is going:
  client->gs->alc->Internet/parent

This is shown in the Via headers.


The alc sibling has a response cached which matches. But that required a
revalidation. (The 113 and 110 Warning headers)

The revalidation failed for some reason (the only-if-cached ?). So it
output a 504 and sent that back to gs. (The 111 Warning header)

There are several problems here:
1) why the revalidation is failing, and
2) why the gs peer is not re-trying the fetch via another server (parent
or DIRECT) after the 504 happens.
3) The Age header says ~46yrs ago for the 504 being created,
suspiciously close to 1 Jan 1970 / unix epoch 0-second.


It seems to me you have managed to reproduce
<http://bugs.squid-cache.org/show_bug.cgi?id=4223>

Amos