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

[zrm]

cache.log for apt-apt-wget-wget with squid -k debug:

https://www.trustiosity.com/squid/cache-debug.log.xz

On 4/6/20 11:49, Alex Rousskov wrote:
> On 4/4/20 8:02 PM, zrm wrote:
>> Attached cache.log excerpt for wget-wget-apt-apt-wget-wget. It answers
>> the apt requests from the cache once it's in there, it just won't cache
>> it to begin with when apt makes the request
> 
> Thank you for sharing this log. I agree with your conclusion. The apt
> query results in cache revalidation and does not purge the already
> cached copy. This conclusion eliminates a few suspects.
> 
> There is probably something special about the combination of an apt
> request and a 200 OK miss response that prevents Squid from caching that
> response. I do not see anything wrong in the logs you have already
> already posted. Perhaps others will spot something.
> 
> If you get no better responses, please post a link to a compressed
> apt-apt-wget-wget log, starting from a cache that does not contain the
> response in question and after enabling elevated Squid debugging with
> "squid -k debug" or similar. You can find more instructions about
> debugging individual transactions at
> https://wiki.squid-cache.org/SquidFaq/BugReporting#Debugging_a_single_transaction
> 
> A detailed apt-apt-wget-wget log should tell us why Squid is refusing to
> cache a 200 OK response to the apt query but caches a very similar
> response to a very similar wget query.
> 
> 
> Thank you,
> 
> Alex.
> 
> 
> 
>> [wget] 1586041686.600    725 192.168.111.55 TCP_MISS/200 1281195 GET
>> http://deb.debian.org/debian/pool/main/v/vim/vim_8.1.0875-5_amd64.deb -
>> ORIGINAL_DST/199.232.66.133 application/x-debian-package
>> [wget] 1586041710.518    107 192.168.111.55 TCP_REFRESH_UNMODIFIED/200
>> 1281232 GET
>> http://deb.debian.org/debian/pool/main/v/vim/vim_8.1.0875-5_amd64.deb -
>> ORIGINAL_DST/199.232.66.133 application/x-debian-package
>> [apt] 1586041733.058     69 192.168.111.55 TCP_REFRESH_UNMODIFIED/200
>> 1281234 GET
>> http://deb.debian.org/debian/pool/main/v/vim/vim_8.1.0875-5_amd64.deb -
>> ORIGINAL_DST/151.101.200.204 application/x-debian-package
>> [apt] 1586041753.971    101 192.168.111.55 TCP_REFRESH_UNMODIFIED/200
>> 1281234 GET
>> http://deb.debian.org/debian/pool/main/v/vim/vim_8.1.0875-5_amd64.deb -
>> ORIGINAL_DST/151.101.200.204 application/x-debian-package
>> [wget] 1586041769.162    160 192.168.111.55 TCP_REFRESH_UNMODIFIED/200
>> 1281232 GET
>> http://deb.debian.org/debian/pool/main/v/vim/vim_8.1.0875-5_amd64.deb -
>> ORIGINAL_DST/199.232.66.133 application/x-debian-package
>> [wget] 1586041786.916     71 192.168.111.55 TCP_REFRESH_UNMODIFIED/200
>> 1281232 GET
>> http://deb.debian.org/debian/pool/main/v/vim/vim_8.1.0875-5_amd64.deb -
>> ORIGINAL_DST/151.101.250.133 application/x-debian-package
>>
>>> 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.
>>
>> In this case we start with wget and then it is already in the cache for
>> the requests made by apt. The problem is the data not being cached when
>> apt makes the request and it isn't already there. The apt requests do
>> get answered from the cache if it is already there.
>>
>> The headers from the previous email show what happens when apt makes the
>> request and it's not already in the cache.
>>
>>>> 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).
>>
>> That makes sense. These packages never really change at all -- the
>> package version is part of the URI so if it's updated the package URI
>> changes rather than the data at the old URI. I might set a longer max
>> age in the config once this is worked out.
>>
>>> HTH,
>>>
>>> Alex.
>>>
>>>
>>
>> Thanks.
>