[squid-users] Squid transparent not caching apt requests from deb.debian.org

Sat Apr 4 14:53:05 UTC 2020

On 4/3/20 4:55 PM, zrm wrote:
> On 4/3/20 16:34, Alex Rousskov wrote:
>> On 4/3/20 4:26 PM, zrm wrote:
>>> In the first case we get TCP_MISS every time because it isn't caching
>>> the data, in the second case it's only the first time and after that we
>>> get TCP_REFRESH_UNMODIFIED. But how and why is this happening?

> squid to apt:
> ---------
> X-Cache: MISS from tproxy
> X-Cache-Lookup: MISS from tproxy:3130

> squid to wget:
> ---------
> X-Cache: MISS from tproxy
> X-Cache-Lookup: MISS from tproxy:3130

The headers you have posted tell us that the object was not in Squid
cache when apt and wget transactions started. Since wget was started
after apt, we can speculate that apt transaction did not cache the
object. This is consistent with your observations. I saw nothing in the
posted headers that would explain the difference between apt and wget
outcomes.

Unfortunately, you did not show the headers for the case where the
object actually got cached by Squid. You can probably do that by
repeating the wget transaction twice. I would also repeat the apt
transaction twice after that. It would also be interesting to see the
wget-apt and apt-wget sequences. In summary, I would do
wget-wget-apt-apt-wget-wget. Sleep for 10+ seconds between each
transaction to reduce chances of overlapping cache operations.

BTW, you probably do not need to make ALL,2 logs pretty -- we can figure
out what happens based on Squid messages if you submit one transaction
at a time and disclose transaction sequence. You can just post (a link
to) raw (or sanitized) logs. Compress them if they are too big.

Before sharing the logs, please double check that the problem you want
to address was reproduced during the test.

> Last-Modified: Sat, 15 Jun 2019 17:46:35 GMT
> ETag: "1389dc-58b605823fa6e"
> Cache-Control: public, max-age=2592000
> Content-Length: 1280476
> Age: 4248100

FWIW: The object is 4'248'100 seconds old. The object max-age is
2'592'000 seconds. Your Squid is probably using an internal max-age of
259'200 seconds, so Squid will require cache hit revalidation during
subsequent transactions after Squid caches the object (if it caches it).

HTH,

Alex.

> apt to squid:
> ---------
> GET /debian/pool/main/v/vim/vim_8.1.0875-5_amd64.deb HTTP/1.1
> Host: deb.debian.org
> User-Agent: Debian APT-HTTP/1.3 (1.8.2)
> 
> 
> ----------
> squid to deb.debian.org:
> ---------
> GET /debian/pool/main/v/vim/vim_8.1.0875-5_amd64.deb HTTP/1.1
> User-Agent: Debian APT-HTTP/1.3 (1.8.2)
> Host: deb.debian.org
> Via: 1.1 tproxy (squid/4.6)
> X-Forwarded-For: 192.168.111.55
> Cache-Control: max-age=259200
> Connection: keep-alive
> 
> 
> ----------
> deb.debian.org to squid:
> ---------
> HTTP/1.1 200 OK
> Server: Apache
> X-Content-Type-Options: nosniff
> X-Frame-Options: sameorigin
> Referrer-Policy: no-referrer
> X-Xss-Protection: 1
> Last-Modified: Sat, 15 Jun 2019 17:46:35 GMT
> ETag: "1389dc-58b605823fa6e"
> X-Clacks-Overhead: GNU Terry Pratchett
> Cache-Control: public, max-age=2592000
> Content-Type: application/x-debian-package
> Via: 1.1 varnish
> Content-Length: 1280476
> Accept-Ranges: bytes
> Date: Fri, 03 Apr 2020 05:28:46 GMT
> Via: 1.1 varnish
> Age: 4248100
> Connection: keep-alive
> X-Served-By: cache-ams21028-AMS, cache-wdc5559-WDC
> X-Cache: HIT, HIT
> X-Cache-Hits: 1, 2
> X-Timer: S1585891726.434375,VS0,VE0
> 
> ----------
> squid to apt:
> ---------
> HTTP/1.1 200 OK
> Server: Apache
> X-Content-Type-Options: nosniff
> X-Frame-Options: sameorigin
> Referrer-Policy: no-referrer
> X-Xss-Protection: 1
> Last-Modified: Sat, 15 Jun 2019 17:46:35 GMT
> ETag: "1389dc-58b605823fa6e"
> X-Clacks-Overhead: GNU Terry Pratchett
> Cache-Control: public, max-age=2592000
> Content-Type: application/x-debian-package
> Content-Length: 1280476
> Accept-Ranges: bytes
> Date: Fri, 03 Apr 2020 05:28:46 GMT
> Age: 4248100
> X-Served-By: cache-ams21028-AMS, cache-wdc5559-WDC
> X-Cache: HIT, HIT
> X-Cache-Hits: 1, 2
> X-Timer: S1585891726.434375,VS0,VE0
> X-Cache: MISS from tproxy
> X-Cache-Lookup: MISS from tproxy:3130
> Via: 1.1 varnish, 1.1 varnish, 1.1 tproxy (squid/4.6)
> Connection: keep-alive
> 
> 
> ----------
> 
> 
> 
> wget to squid:
> ---------
> GET /debian/pool/main/v/vim/vim_8.1.0875-5_amd64.deb HTTP/1.1
> User-Agent: Wget/1.20.1 (linux-gnu)
> Accept: */*
> Accept-Encoding: identity
> Host: deb.debian.org
> Connection: Keep-Alive
> 
> 
> ----------
> squid to deb.debian.org:
> ----------
> GET /debian/pool/main/v/vim/vim_8.1.0875-5_amd64.deb HTTP/1.1
> User-Agent: Wget/1.20.1 (linux-gnu)
> Accept: */*
> Accept-Encoding: identity
> Host: deb.debian.org
> Via: 1.1 tproxy (squid/4.6)
> X-Forwarded-For: 192.168.111.55
> Cache-Control: max-age=259200
> Connection: keep-alive
> 
> 
> ----------
> deb.debian.org to squid:
> ---------
> HTTP/1.1 200 OK
> Server: Apache
> X-Content-Type-Options: nosniff
> X-Frame-Options: sameorigin
> Referrer-Policy: no-referrer
> X-Xss-Protection: 1
> Last-Modified: Sat, 15 Jun 2019 17:46:35 GMT
> ETag: "1389dc-58b605823fa6e"
> X-Clacks-Overhead: GNU Terry Pratchett
> Cache-Control: public, max-age=2592000
> Content-Type: application/x-debian-package
> Via: 1.1 varnish
> Content-Length: 1280476
> Accept-Ranges: bytes
> Date: Fri, 03 Apr 2020 05:28:49 GMT
> Via: 1.1 varnish
> Age: 4248102
> Connection: keep-alive
> X-Served-By: cache-ams21028-AMS, cache-wdc5583-WDC
> X-Cache: HIT, HIT
> X-Cache-Hits: 1, 1
> X-Timer: S1585891729.316362,VS0,VE0
> 
> ----------
> squid to wget:
> ---------
> HTTP/1.1 200 OK
> Server: Apache
> X-Content-Type-Options: nosniff
> X-Frame-Options: sameorigin
> Referrer-Policy: no-referrer
> X-Xss-Protection: 1
> Last-Modified: Sat, 15 Jun 2019 17:46:35 GMT
> ETag: "1389dc-58b605823fa6e"
> X-Clacks-Overhead: GNU Terry Pratchett
> Cache-Control: public, max-age=2592000
> Content-Type: application/x-debian-package
> Content-Length: 1280476
> Accept-Ranges: bytes
> Date: Fri, 03 Apr 2020 05:28:49 GMT
> Age: 4248102
> X-Served-By: cache-ams21028-AMS, cache-wdc5583-WDC
> X-Cache: HIT, HIT
> X-Cache-Hits: 1, 1
> X-Timer: S1585891729.316362,VS0,VE0
> X-Cache: MISS from tproxy
> X-Cache-Lookup: MISS from tproxy:3130
> Via: 1.1 varnish, 1.1 varnish, 1.1 tproxy (squid/4.6)
> Connection: keep-alive
> 
> 
> ----------