On 4/4/20 10:53, Alex Rousskov wrote:
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.
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:
[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.
2020/04/04 19:08:05.874 kid1| 5,2| TcpAcceptor.cc(224) doAccept: New connection on FD 15
2020/04/04 19:08:05.874 kid1| 5,2| TcpAcceptor.cc(317) acceptNext: connection on local=[::]:3128 remote=[::] FD 15 flags=41
2020/04/04 19:08:05.874 kid1| 11,2| client_side.cc(1319) parseHttpRequest: HTTP Client local=199.232.66.133:80 remote=192.168.111.55:47028 FD 11 flags=33
2020/04/04 19:08:05.874 kid1| 11,2| client_side.cc(1323) parseHttpRequest: HTTP Client REQUEST:
---------
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
----------
2020/04/04 19:08:05.875 kid1| 85,2| client_side_request.cc(752) clientAccessCheckDone: The request GET http://deb.debian.org/debian/pool/main/v/vim/vim_8.1.0875-5_amd64.deb is ALLOWED; last ACL checked: localnet
2020/04/04 19:08:05.875 kid1| 85,2| client_side_request.cc(728) clientAccessCheck2: No adapted_http_access configuration. default: ALLOW
2020/04/04 19:08:05.875 kid1| 85,2| client_side_request.cc(752) clientAccessCheckDone: The request GET http://deb.debian.org/debian/pool/main/v/vim/vim_8.1.0875-5_amd64.deb is ALLOWED; last ACL checked: localnet
2020/04/04 19:08:05.876 kid1| 17,2| FwdState.cc(142) FwdState: Forwarding client request local=199.232.66.133:80 remote=192.168.111.55:47028 FD 11 flags=33, url=http://deb.debian.org/debian/pool/main/v/vim/vim_8.1.0875-5_amd64.deb
2020/04/04 19:08:05.876 kid1| 44,2| peer_select.cc(302) peerSelectDnsPaths: Found sources for 'http://deb.debian.org/debian/pool/main/v/vim/vim_8.1.0875-5_amd64.deb'
2020/04/04 19:08:05.876 kid1| 44,2| peer_select.cc(303) peerSelectDnsPaths: always_direct = DENIED
2020/04/04 19:08:05.876 kid1| 44,2| peer_select.cc(304) peerSelectDnsPaths: never_direct = DENIED
2020/04/04 19:08:05.876 kid1| 44,2| peer_select.cc(310) peerSelectDnsPaths: ORIGINAL_DST = local=0.0.0.0 remote=199.232.66.133:80 flags=1
2020/04/04 19:08:05.876 kid1| 44,2| peer_select.cc(317) peerSelectDnsPaths: timedout = 0
2020/04/04 19:08:05.955 kid1| 37,2| IcmpSquid.cc(91) SendEcho: to [2a04:4e42:2f::645], opcode 3, len 14
2020/04/04 19:08:05.955| 42,2| IcmpPinger.cc(196) Recv: Pass [2a04:4e42:2f::645] off to ICMPv6 module.
2020/04/04 19:08:05.955| SendEcho ERROR: sending to ICMPv6 packet to [2a04:4e42:2f::645]: (101) Network is unreachable
2020/04/04 19:08:05.955| 42,2| Icmp.cc(95) Log: pingerLog: 1586041685.955279 [2a04:4e42:2f::645] 0
2020/04/04 19:08:05.955 kid1| 11,2| http.cc(2260) sendRequest: HTTP Server local=192.168.111.151:37680 remote=199.232.66.133:80 FD 13 flags=1
2020/04/04 19:08:05.955 kid1| 11,2| http.cc(2261) sendRequest: HTTP Server REQUEST:
---------
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
----------
2020/04/04 19:08:06.052 kid1| ctx: enter level 0: 'http://deb.debian.org/debian/pool/main/v/vim/vim_8.1.0875-5_amd64.deb'
2020/04/04 19:08:06.052 kid1| 11,2| http.cc(719) processReplyHeader: HTTP Server local=192.168.111.151:37680 remote=199.232.66.133:80 FD 13 flags=1
2020/04/04 19:08:06.052 kid1| 11,2| http.cc(723) processReplyHeader: HTTP Server RESPONSE:
---------
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: Sat, 04 Apr 2020 23:08:05 GMT
Via: 1.1 varnish
Age: 4398059
Connection: keep-alive
X-Served-By: cache-ams21028-AMS, cache-wdc5560-WDC
X-Cache: HIT, HIT
X-Cache-Hits: 1, 1
X-Timer: S1586041686.977532,VS0,VE0
----------
2020/04/04 19:08:06.052 kid1| ctx: exit level 0
2020/04/04 19:08:06.052 kid1| 88,2| client_side_reply.cc(2061) processReplyAccessResult: The reply for GET http://deb.debian.org/debian/pool/main/v/vim/vim_8.1.0875-5_amd64.deb is ALLOWED, because it matched localnet
2020/04/04 19:08:06.052 kid1| 11,2| Stream.cc(266) sendStartOfMessage: HTTP Client local=199.232.66.133:80 remote=192.168.111.55:47028 FD 11 flags=33
2020/04/04 19:08:06.052 kid1| 11,2| Stream.cc(267) sendStartOfMessage: HTTP Client REPLY:
---------
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: Sat, 04 Apr 2020 23:08:05 GMT
Age: 4398059
X-Served-By: cache-ams21028-AMS, cache-wdc5560-WDC
X-Cache: HIT, HIT
X-Cache-Hits: 1, 1
X-Timer: S1586041686.977532,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
----------
2020/04/04 19:08:06.602 kid1| 33,2| client_side.cc(582) swanSong: local=199.232.66.133:80 remote=192.168.111.55:47028 flags=33
2020/04/04 19:08:30.410 kid1| 5,2| TcpAcceptor.cc(224) doAccept: New connection on FD 15
2020/04/04 19:08:30.410 kid1| 5,2| TcpAcceptor.cc(317) acceptNext: connection on local=[::]:3128 remote=[::] FD 15 flags=41
2020/04/04 19:08:30.410 kid1| 11,2| client_side.cc(1319) parseHttpRequest: HTTP Client local=199.232.66.133:80 remote=192.168.111.55:47030 FD 11 flags=33
2020/04/04 19:08:30.410 kid1| 11,2| client_side.cc(1323) parseHttpRequest: HTTP Client REQUEST:
---------
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
----------
2020/04/04 19:08:30.410 kid1| 85,2| client_side_request.cc(752) clientAccessCheckDone: The request GET http://deb.debian.org/debian/pool/main/v/vim/vim_8.1.0875-5_amd64.deb is ALLOWED; last ACL checked: localnet
2020/04/04 19:08:30.410 kid1| 85,2| client_side_request.cc(728) clientAccessCheck2: No adapted_http_access configuration. default: ALLOW
2020/04/04 19:08:30.410 kid1| 85,2| client_side_request.cc(752) clientAccessCheckDone: The request GET http://deb.debian.org/debian/pool/main/v/vim/vim_8.1.0875-5_amd64.deb is ALLOWED; last ACL checked: localnet
2020/04/04 19:08:30.410 kid1| 17,2| FwdState.cc(142) FwdState: Forwarding client request local=199.232.66.133:80 remote=192.168.111.55:47030 FD 11 flags=33, url=http://deb.debian.org/debian/pool/main/v/vim/vim_8.1.0875-5_amd64.deb
2020/04/04 19:08:30.410 kid1| 44,2| peer_select.cc(302) peerSelectDnsPaths: Found sources for 'http://deb.debian.org/debian/pool/main/v/vim/vim_8.1.0875-5_amd64.deb'
2020/04/04 19:08:30.410 kid1| 44,2| peer_select.cc(303) peerSelectDnsPaths: always_direct = DENIED
2020/04/04 19:08:30.410 kid1| 44,2| peer_select.cc(304) peerSelectDnsPaths: never_direct = DENIED
2020/04/04 19:08:30.411 kid1| 44,2| peer_select.cc(310) peerSelectDnsPaths: ORIGINAL_DST = local=0.0.0.0 remote=199.232.66.133:80 flags=1
2020/04/04 19:08:30.411 kid1| 44,2| peer_select.cc(317) peerSelectDnsPaths: timedout = 0
2020/04/04 19:08:30.411 kid1| 11,2| http.cc(2260) sendRequest: HTTP Server local=192.168.111.151:37680 remote=199.232.66.133:80 FD 13 flags=1
2020/04/04 19:08:30.411 kid1| 11,2| http.cc(2261) sendRequest: HTTP Server REQUEST:
---------
GET /debian/pool/main/v/vim/vim_8.1.0875-5_amd64.deb HTTP/1.1
If-Modified-Since: Sat, 15 Jun 2019 17:46:35 GMT
If-None-Match: "1389dc-58b605823fa6e"
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
----------
2020/04/04 19:08:30.506 kid1| ctx: enter level 0: 'http://deb.debian.org/debian/pool/main/v/vim/vim_8.1.0875-5_amd64.deb'
2020/04/04 19:08:30.506 kid1| 11,2| http.cc(719) processReplyHeader: HTTP Server local=192.168.111.151:37680 remote=199.232.66.133:80 FD 13 flags=1
2020/04/04 19:08:30.506 kid1| 11,2| http.cc(723) processReplyHeader: HTTP Server RESPONSE:
---------
HTTP/1.1 304 Not Modified
Date: Sat, 04 Apr 2020 23:08:30 GMT
Via: 1.1 varnish
Cache-Control: public, max-age=2592000
ETag: "1389dc-58b605823fa6e"
Age: 4398083
Connection: keep-alive
X-Served-By: cache-wdc5560-WDC
X-Cache: HIT
X-Cache-Hits: 2
X-Timer: S1586041710.427654,VS0,VE0
----------
2020/04/04 19:08:30.506 kid1| ctx: exit level 0
2020/04/04 19:08:30.506 kid1| 20,2| store.cc(980) checkCachable: StoreEntry::checkCachable: NO: not cachable
2020/04/04 19:08:30.506 kid1| 88,2| client_side_reply.cc(2061) processReplyAccessResult: The reply for GET http://deb.debian.org/debian/pool/main/v/vim/vim_8.1.0875-5_amd64.deb is ALLOWED, because it matched localnet
2020/04/04 19:08:30.506 kid1| 11,2| Stream.cc(266) sendStartOfMessage: HTTP Client local=199.232.66.133:80 remote=192.168.111.55:47030 FD 11 flags=33
2020/04/04 19:08:30.506 kid1| 11,2| Stream.cc(267) sendStartOfMessage: HTTP Client REPLY:
---------
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
X-Clacks-Overhead: GNU Terry Pratchett
Content-Type: application/x-debian-package
Content-Length: 1280476
Accept-Ranges: bytes
Date: Sat, 04 Apr 2020 23:08:30 GMT
Cache-Control: public, max-age=2592000
ETag: "1389dc-58b605823fa6e"
X-Served-By: cache-wdc5560-WDC
X-Cache: HIT
X-Cache-Hits: 2
X-Timer: S1586041710.427654,VS0,VE0
Age: 4398083
Warning: 113 squid/4.6 "This cache hit is still fresh and more than 1 day old"
X-Cache: HIT from tproxy
X-Cache-Lookup: HIT from tproxy:3130
Via: 1.1 varnish, 1.1 tproxy (squid/4.6)
Connection: keep-alive
----------
2020/04/04 19:08:30.506 kid1| 17,2| FwdState.cc(678) handleUnregisteredServerEnd: self=0x5631ef5741d8*2 err=0 http://deb.debian.org/debian/pool/main/v/vim/vim_8.1.0875-5_amd64.deb
2020/04/04 19:08:30.522 kid1| 33,2| client_side.cc(582) swanSong: local=199.232.66.133:80 remote=192.168.111.55:47030 flags=33
2020/04/04 19:08:52.988 kid1| 5,2| TcpAcceptor.cc(224) doAccept: New connection on FD 15
2020/04/04 19:08:52.988 kid1| 5,2| TcpAcceptor.cc(317) acceptNext: connection on local=[::]:3128 remote=[::] FD 15 flags=41
2020/04/04 19:08:52.989 kid1| 11,2| client_side.cc(1319) parseHttpRequest: HTTP Client local=151.101.200.204:80 remote=192.168.111.55:38222 FD 11 flags=33
2020/04/04 19:08:52.989 kid1| 11,2| client_side.cc(1323) parseHttpRequest: HTTP Client REQUEST:
---------
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)
----------
2020/04/04 19:08:52.989 kid1| 85,2| client_side_request.cc(752) clientAccessCheckDone: The request GET http://deb.debian.org/debian/pool/main/v/vim/vim_8.1.0875-5_amd64.deb is ALLOWED; last ACL checked: localnet
2020/04/04 19:08:52.989 kid1| 85,2| client_side_request.cc(728) clientAccessCheck2: No adapted_http_access configuration. default: ALLOW
2020/04/04 19:08:52.989 kid1| 85,2| client_side_request.cc(752) clientAccessCheckDone: The request GET http://deb.debian.org/debian/pool/main/v/vim/vim_8.1.0875-5_amd64.deb is ALLOWED; last ACL checked: localnet
2020/04/04 19:08:52.989 kid1| 17,2| FwdState.cc(142) FwdState: Forwarding client request local=151.101.200.204:80 remote=192.168.111.55:38222 FD 11 flags=33, url=http://deb.debian.org/debian/pool/main/v/vim/vim_8.1.0875-5_amd64.deb
2020/04/04 19:08:52.989 kid1| 44,2| peer_select.cc(302) peerSelectDnsPaths: Found sources for 'http://deb.debian.org/debian/pool/main/v/vim/vim_8.1.0875-5_amd64.deb'
2020/04/04 19:08:52.989 kid1| 44,2| peer_select.cc(303) peerSelectDnsPaths: always_direct = DENIED
2020/04/04 19:08:52.989 kid1| 44,2| peer_select.cc(304) peerSelectDnsPaths: never_direct = DENIED
2020/04/04 19:08:52.989 kid1| 44,2| peer_select.cc(310) peerSelectDnsPaths: ORIGINAL_DST = local=0.0.0.0 remote=151.101.200.204:80 flags=1
2020/04/04 19:08:52.989 kid1| 44,2| peer_select.cc(317) peerSelectDnsPaths: timedout = 0
2020/04/04 19:08:53.016 kid1| 11,2| http.cc(2260) sendRequest: HTTP Server local=192.168.111.151:35452 remote=151.101.200.204:80 FD 13 flags=1
2020/04/04 19:08:53.017 kid1| 11,2| http.cc(2261) sendRequest: HTTP Server REQUEST:
---------
GET /debian/pool/main/v/vim/vim_8.1.0875-5_amd64.deb HTTP/1.1
If-Modified-Since: Sat, 15 Jun 2019 17:46:35 GMT
If-None-Match: "1389dc-58b605823fa6e"
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
----------
2020/04/04 19:08:53.048 kid1| ctx: enter level 0: 'http://deb.debian.org/debian/pool/main/v/vim/vim_8.1.0875-5_amd64.deb'
2020/04/04 19:08:53.048 kid1| 11,2| http.cc(719) processReplyHeader: HTTP Server local=192.168.111.151:35452 remote=151.101.200.204:80 FD 13 flags=1
2020/04/04 19:08:53.048 kid1| 11,2| http.cc(723) processReplyHeader: HTTP Server RESPONSE:
---------
HTTP/1.1 304 Not Modified
Date: Sat, 04 Apr 2020 23:08:53 GMT
Via: 1.1 varnish
Cache-Control: public, max-age=2592000
ETag: "1389dc-58b605823fa6e"
Age: 17482479
Connection: keep-alive
X-Served-By: cache-dca17780-DCA
X-Cache: HIT
X-Cache-Hits: 1
X-Timer: S1586041733.037536,VS0,VE0
----------
2020/04/04 19:08:53.048 kid1| ctx: exit level 0
2020/04/04 19:08:53.048 kid1| 20,2| store.cc(980) checkCachable: StoreEntry::checkCachable: NO: not cachable
2020/04/04 19:08:53.048 kid1| 88,2| client_side_reply.cc(2061) processReplyAccessResult: The reply for GET http://deb.debian.org/debian/pool/main/v/vim/vim_8.1.0875-5_amd64.deb is ALLOWED, because it matched localnet
2020/04/04 19:08:53.048 kid1| 11,2| Stream.cc(266) sendStartOfMessage: HTTP Client local=151.101.200.204:80 remote=192.168.111.55:38222 FD 11 flags=33
2020/04/04 19:08:53.048 kid1| 11,2| Stream.cc(267) sendStartOfMessage: HTTP Client REPLY:
---------
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
X-Clacks-Overhead: GNU Terry Pratchett
Content-Type: application/x-debian-package
Content-Length: 1280476
Accept-Ranges: bytes
Date: Sat, 04 Apr 2020 23:08:53 GMT
Cache-Control: public, max-age=2592000
ETag: "1389dc-58b605823fa6e"
X-Served-By: cache-dca17780-DCA
X-Cache: HIT
X-Cache-Hits: 1
X-Timer: S1586041733.037536,VS0,VE0
Age: 17482479
Warning: 113 squid/4.6 "This cache hit is still fresh and more than 1 day old"
X-Cache: HIT from tproxy
X-Cache-Lookup: HIT from tproxy:3130
Via: 1.1 varnish, 1.1 tproxy (squid/4.6)
Connection: keep-alive
----------
2020/04/04 19:08:53.048 kid1| 17,2| FwdState.cc(678) handleUnregisteredServerEnd: self=0x5631ef5741d8*2 err=0 http://deb.debian.org/debian/pool/main/v/vim/vim_8.1.0875-5_amd64.deb
2020/04/04 19:08:53.065 kid1| 33,2| client_side.cc(582) swanSong: local=151.101.200.204:80 remote=192.168.111.55:38222 flags=33
2020/04/04 19:09:13.869 kid1| 5,2| TcpAcceptor.cc(224) doAccept: New connection on FD 15
2020/04/04 19:09:13.869 kid1| 5,2| TcpAcceptor.cc(317) acceptNext: connection on local=[::]:3128 remote=[::] FD 15 flags=41
2020/04/04 19:09:13.869 kid1| 11,2| client_side.cc(1319) parseHttpRequest: HTTP Client local=151.101.200.204:80 remote=192.168.111.55:38224 FD 11 flags=33
2020/04/04 19:09:13.869 kid1| 11,2| client_side.cc(1323) parseHttpRequest: HTTP Client REQUEST:
---------
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)
----------
2020/04/04 19:09:13.900 kid1| 85,2| client_side_request.cc(752) clientAccessCheckDone: The request GET http://deb.debian.org/debian/pool/main/v/vim/vim_8.1.0875-5_amd64.deb is ALLOWED; last ACL checked: localnet
2020/04/04 19:09:13.900 kid1| 85,2| client_side_request.cc(728) clientAccessCheck2: No adapted_http_access configuration. default: ALLOW
2020/04/04 19:09:13.900 kid1| 85,2| client_side_request.cc(752) clientAccessCheckDone: The request GET http://deb.debian.org/debian/pool/main/v/vim/vim_8.1.0875-5_amd64.deb is ALLOWED; last ACL checked: localnet
2020/04/04 19:09:13.900 kid1| 17,2| FwdState.cc(142) FwdState: Forwarding client request local=151.101.200.204:80 remote=192.168.111.55:38224 FD 11 flags=33, url=http://deb.debian.org/debian/pool/main/v/vim/vim_8.1.0875-5_amd64.deb
2020/04/04 19:09:13.900 kid1| 44,2| peer_select.cc(302) peerSelectDnsPaths: Found sources for 'http://deb.debian.org/debian/pool/main/v/vim/vim_8.1.0875-5_amd64.deb'
2020/04/04 19:09:13.900 kid1| 44,2| peer_select.cc(303) peerSelectDnsPaths: always_direct = DENIED
2020/04/04 19:09:13.900 kid1| 44,2| peer_select.cc(304) peerSelectDnsPaths: never_direct = DENIED
2020/04/04 19:09:13.900 kid1| 44,2| peer_select.cc(310) peerSelectDnsPaths: ORIGINAL_DST = local=0.0.0.0 remote=151.101.200.204:80 flags=1
2020/04/04 19:09:13.900 kid1| 44,2| peer_select.cc(317) peerSelectDnsPaths: timedout = 0
2020/04/04 19:09:13.927 kid1| 11,2| http.cc(2260) sendRequest: HTTP Server local=192.168.111.151:35454 remote=151.101.200.204:80 FD 13 flags=1
2020/04/04 19:09:13.927 kid1| 11,2| http.cc(2261) sendRequest: HTTP Server REQUEST:
---------
GET /debian/pool/main/v/vim/vim_8.1.0875-5_amd64.deb HTTP/1.1
If-Modified-Since: Sat, 15 Jun 2019 17:46:35 GMT
If-None-Match: "1389dc-58b605823fa6e"
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
----------
2020/04/04 19:09:13.956 kid1| ctx: enter level 0: 'http://deb.debian.org/debian/pool/main/v/vim/vim_8.1.0875-5_amd64.deb'
2020/04/04 19:09:13.956 kid1| 11,2| http.cc(719) processReplyHeader: HTTP Server local=192.168.111.151:35454 remote=151.101.200.204:80 FD 13 flags=1
2020/04/04 19:09:13.956 kid1| 11,2| http.cc(723) processReplyHeader: HTTP Server RESPONSE:
---------
HTTP/1.1 304 Not Modified
Date: Sat, 04 Apr 2020 23:09:13 GMT
Via: 1.1 varnish
Cache-Control: public, max-age=2592000
ETag: "1389dc-58b605823fa6e"
Age: 17482500
Connection: keep-alive
X-Served-By: cache-dca17769-DCA
X-Cache: HIT
X-Cache-Hits: 1
X-Timer: S1586041754.945690,VS0,VE0
----------
2020/04/04 19:09:13.956 kid1| ctx: exit level 0
2020/04/04 19:09:13.956 kid1| 20,2| store.cc(980) checkCachable: StoreEntry::checkCachable: NO: not cachable
2020/04/04 19:09:13.957 kid1| 88,2| client_side_reply.cc(2061) processReplyAccessResult: The reply for GET http://deb.debian.org/debian/pool/main/v/vim/vim_8.1.0875-5_amd64.deb is ALLOWED, because it matched localnet
2020/04/04 19:09:13.957 kid1| 11,2| Stream.cc(266) sendStartOfMessage: HTTP Client local=151.101.200.204:80 remote=192.168.111.55:38224 FD 11 flags=33
2020/04/04 19:09:13.957 kid1| 11,2| Stream.cc(267) sendStartOfMessage: HTTP Client REPLY:
---------
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
X-Clacks-Overhead: GNU Terry Pratchett
Content-Type: application/x-debian-package
Content-Length: 1280476
Accept-Ranges: bytes
Date: Sat, 04 Apr 2020 23:09:13 GMT
Cache-Control: public, max-age=2592000
ETag: "1389dc-58b605823fa6e"
X-Served-By: cache-dca17769-DCA
X-Cache: HIT
X-Cache-Hits: 1
X-Timer: S1586041754.945690,VS0,VE0
Age: 17482500
Warning: 113 squid/4.6 "This cache hit is still fresh and more than 1 day old"
X-Cache: HIT from tproxy
X-Cache-Lookup: HIT from tproxy:3130
Via: 1.1 varnish, 1.1 tproxy (squid/4.6)
Connection: keep-alive
----------
2020/04/04 19:09:13.957 kid1| 17,2| FwdState.cc(678) handleUnregisteredServerEnd: self=0x5631ef5741d8*2 err=0 http://deb.debian.org/debian/pool/main/v/vim/vim_8.1.0875-5_amd64.deb
2020/04/04 19:09:13.974 kid1| 33,2| client_side.cc(582) swanSong: local=151.101.200.204:80 remote=192.168.111.55:38224 flags=33
2020/04/04 19:09:29.001 kid1| 5,2| TcpAcceptor.cc(224) doAccept: New connection on FD 15
2020/04/04 19:09:29.001 kid1| 5,2| TcpAcceptor.cc(317) acceptNext: connection on local=[::]:3128 remote=[::] FD 15 flags=41
2020/04/04 19:09:29.001 kid1| 11,2| client_side.cc(1319) parseHttpRequest: HTTP Client local=199.232.66.133:80 remote=192.168.111.55:47036 FD 11 flags=33
2020/04/04 19:09:29.001 kid1| 11,2| client_side.cc(1323) parseHttpRequest: HTTP Client REQUEST:
---------
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
----------
2020/04/04 19:09:29.002 kid1| 85,2| client_side_request.cc(752) clientAccessCheckDone: The request GET http://deb.debian.org/debian/pool/main/v/vim/vim_8.1.0875-5_amd64.deb is ALLOWED; last ACL checked: localnet
2020/04/04 19:09:29.002 kid1| 85,2| client_side_request.cc(728) clientAccessCheck2: No adapted_http_access configuration. default: ALLOW
2020/04/04 19:09:29.002 kid1| 85,2| client_side_request.cc(752) clientAccessCheckDone: The request GET http://deb.debian.org/debian/pool/main/v/vim/vim_8.1.0875-5_amd64.deb is ALLOWED; last ACL checked: localnet
2020/04/04 19:09:29.002 kid1| 17,2| FwdState.cc(142) FwdState: Forwarding client request local=199.232.66.133:80 remote=192.168.111.55:47036 FD 11 flags=33, url=http://deb.debian.org/debian/pool/main/v/vim/vim_8.1.0875-5_amd64.deb
2020/04/04 19:09:29.002 kid1| 44,2| peer_select.cc(302) peerSelectDnsPaths: Found sources for 'http://deb.debian.org/debian/pool/main/v/vim/vim_8.1.0875-5_amd64.deb'
2020/04/04 19:09:29.002 kid1| 44,2| peer_select.cc(303) peerSelectDnsPaths: always_direct = DENIED
2020/04/04 19:09:29.002 kid1| 44,2| peer_select.cc(304) peerSelectDnsPaths: never_direct = DENIED
2020/04/04 19:09:29.002 kid1| 44,2| peer_select.cc(310) peerSelectDnsPaths: ORIGINAL_DST = local=0.0.0.0 remote=199.232.66.133:80 flags=1
2020/04/04 19:09:29.002 kid1| 44,2| peer_select.cc(317) peerSelectDnsPaths: timedout = 0
2020/04/04 19:09:29.077 kid1| 11,2| http.cc(2260) sendRequest: HTTP Server local=192.168.111.151:37686 remote=199.232.66.133:80 FD 13 flags=1
2020/04/04 19:09:29.077 kid1| 11,2| http.cc(2261) sendRequest: HTTP Server REQUEST:
---------
GET /debian/pool/main/v/vim/vim_8.1.0875-5_amd64.deb HTTP/1.1
If-Modified-Since: Sat, 15 Jun 2019 17:46:35 GMT
If-None-Match: "1389dc-58b605823fa6e"
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
----------
2020/04/04 19:09:29.151 kid1| ctx: enter level 0: 'http://deb.debian.org/debian/pool/main/v/vim/vim_8.1.0875-5_amd64.deb'
2020/04/04 19:09:29.151 kid1| 11,2| http.cc(719) processReplyHeader: HTTP Server local=192.168.111.151:37686 remote=199.232.66.133:80 FD 13 flags=1
2020/04/04 19:09:29.151 kid1| 11,2| http.cc(723) processReplyHeader: HTTP Server RESPONSE:
---------
HTTP/1.1 304 Not Modified
Date: Sat, 04 Apr 2020 23:09:29 GMT
Via: 1.1 varnish
Cache-Control: public, max-age=2592000
ETag: "1389dc-58b605823fa6e"
Age: 4398142
Connection: keep-alive
X-Served-By: cache-wdc5547-WDC
X-Cache: HIT
X-Cache-Hits: 1
X-Timer: S1586041769.097130,VS0,VE0
----------
2020/04/04 19:09:29.151 kid1| ctx: exit level 0
2020/04/04 19:09:29.151 kid1| 20,2| store.cc(980) checkCachable: StoreEntry::checkCachable: NO: not cachable
2020/04/04 19:09:29.151 kid1| 88,2| client_side_reply.cc(2061) processReplyAccessResult: The reply for GET http://deb.debian.org/debian/pool/main/v/vim/vim_8.1.0875-5_amd64.deb is ALLOWED, because it matched localnet
2020/04/04 19:09:29.151 kid1| 11,2| Stream.cc(266) sendStartOfMessage: HTTP Client local=199.232.66.133:80 remote=192.168.111.55:47036 FD 11 flags=33
2020/04/04 19:09:29.151 kid1| 11,2| Stream.cc(267) sendStartOfMessage: HTTP Client REPLY:
---------
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
X-Clacks-Overhead: GNU Terry Pratchett
Content-Type: application/x-debian-package
Content-Length: 1280476
Accept-Ranges: bytes
Date: Sat, 04 Apr 2020 23:09:29 GMT
Cache-Control: public, max-age=2592000
ETag: "1389dc-58b605823fa6e"
X-Served-By: cache-wdc5547-WDC
X-Cache: HIT
X-Cache-Hits: 1
X-Timer: S1586041769.097130,VS0,VE0
Age: 4398142
Warning: 113 squid/4.6 "This cache hit is still fresh and more than 1 day old"
X-Cache: HIT from tproxy
X-Cache-Lookup: HIT from tproxy:3130
Via: 1.1 varnish, 1.1 tproxy (squid/4.6)
Connection: keep-alive
----------
2020/04/04 19:09:29.151 kid1| 17,2| FwdState.cc(678) handleUnregisteredServerEnd: self=0x5631ef5741d8*2 err=0 http://deb.debian.org/debian/pool/main/v/vim/vim_8.1.0875-5_amd64.deb
2020/04/04 19:09:29.166 kid1| 33,2| client_side.cc(582) swanSong: local=199.232.66.133:80 remote=192.168.111.55:47036 flags=33
2020/04/04 19:09:46.844 kid1| 5,2| TcpAcceptor.cc(224) doAccept: New connection on FD 15
2020/04/04 19:09:46.844 kid1| 5,2| TcpAcceptor.cc(317) acceptNext: connection on local=[::]:3128 remote=[::] FD 15 flags=41
2020/04/04 19:09:46.845 kid1| 11,2| client_side.cc(1319) parseHttpRequest: HTTP Client local=151.101.250.133:80 remote=192.168.111.55:47890 FD 11 flags=33
2020/04/04 19:09:46.845 kid1| 11,2| client_side.cc(1323) parseHttpRequest: HTTP Client REQUEST:
---------
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
----------
2020/04/04 19:09:46.845 kid1| 85,2| client_side_request.cc(752) clientAccessCheckDone: The request GET http://deb.debian.org/debian/pool/main/v/vim/vim_8.1.0875-5_amd64.deb is ALLOWED; last ACL checked: localnet
2020/04/04 19:09:46.845 kid1| 85,2| client_side_request.cc(728) clientAccessCheck2: No adapted_http_access configuration. default: ALLOW
2020/04/04 19:09:46.845 kid1| 85,2| client_side_request.cc(752) clientAccessCheckDone: The request GET http://deb.debian.org/debian/pool/main/v/vim/vim_8.1.0875-5_amd64.deb is ALLOWED; last ACL checked: localnet
2020/04/04 19:09:46.845 kid1| 17,2| FwdState.cc(142) FwdState: Forwarding client request local=151.101.250.133:80 remote=192.168.111.55:47890 FD 11 flags=33, url=http://deb.debian.org/debian/pool/main/v/vim/vim_8.1.0875-5_amd64.deb
2020/04/04 19:09:46.845 kid1| 44,2| peer_select.cc(302) peerSelectDnsPaths: Found sources for 'http://deb.debian.org/debian/pool/main/v/vim/vim_8.1.0875-5_amd64.deb'
2020/04/04 19:09:46.845 kid1| 44,2| peer_select.cc(303) peerSelectDnsPaths: always_direct = DENIED
2020/04/04 19:09:46.845 kid1| 44,2| peer_select.cc(304) peerSelectDnsPaths: never_direct = DENIED
2020/04/04 19:09:46.845 kid1| 44,2| peer_select.cc(310) peerSelectDnsPaths: ORIGINAL_DST = local=0.0.0.0 remote=151.101.250.133:80 flags=1
2020/04/04 19:09:46.845 kid1| 44,2| peer_select.cc(317) peerSelectDnsPaths: timedout = 0
2020/04/04 19:09:46.874 kid1| 11,2| http.cc(2260) sendRequest: HTTP Server local=192.168.111.151:37272 remote=151.101.250.133:80 FD 13 flags=1
2020/04/04 19:09:46.874 kid1| 11,2| http.cc(2261) sendRequest: HTTP Server REQUEST:
---------
GET /debian/pool/main/v/vim/vim_8.1.0875-5_amd64.deb HTTP/1.1
If-Modified-Since: Sat, 15 Jun 2019 17:46:35 GMT
If-None-Match: "1389dc-58b605823fa6e"
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
----------
2020/04/04 19:09:46.901 kid1| ctx: enter level 0: 'http://deb.debian.org/debian/pool/main/v/vim/vim_8.1.0875-5_amd64.deb'
2020/04/04 19:09:46.901 kid1| 11,2| http.cc(719) processReplyHeader: HTTP Server local=192.168.111.151:37272 remote=151.101.250.133:80 FD 13 flags=1
2020/04/04 19:09:46.901 kid1| 11,2| http.cc(723) processReplyHeader: HTTP Server RESPONSE:
---------
HTTP/1.1 304 Not Modified
Date: Sat, 04 Apr 2020 23:09:46 GMT
Via: 1.1 varnish
Cache-Control: public, max-age=2592000
ETag: "1389dc-58b605823fa6e"
Age: 1729937
Connection: keep-alive
X-Served-By: cache-bwi5046-BWI
X-Cache: HIT
X-Cache-Hits: 1
X-Timer: S1586041787.890575,VS0,VE1
----------
2020/04/04 19:09:46.901 kid1| ctx: exit level 0
2020/04/04 19:09:46.901 kid1| 20,2| store.cc(980) checkCachable: StoreEntry::checkCachable: NO: not cachable
2020/04/04 19:09:46.901 kid1| 88,2| client_side_reply.cc(2061) processReplyAccessResult: The reply for GET http://deb.debian.org/debian/pool/main/v/vim/vim_8.1.0875-5_amd64.deb is ALLOWED, because it matched localnet
2020/04/04 19:09:46.902 kid1| 11,2| Stream.cc(266) sendStartOfMessage: HTTP Client local=151.101.250.133:80 remote=192.168.111.55:47890 FD 11 flags=33
2020/04/04 19:09:46.902 kid1| 11,2| Stream.cc(267) sendStartOfMessage: HTTP Client REPLY:
---------
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
X-Clacks-Overhead: GNU Terry Pratchett
Content-Type: application/x-debian-package
Content-Length: 1280476
Accept-Ranges: bytes
Date: Sat, 04 Apr 2020 23:09:46 GMT
Cache-Control: public, max-age=2592000
ETag: "1389dc-58b605823fa6e"
X-Served-By: cache-bwi5046-BWI
X-Cache: HIT
X-Cache-Hits: 1
X-Timer: S1586041787.890575,VS0,VE1
Age: 1729937
Warning: 113 squid/4.6 "This cache hit is still fresh and more than 1 day old"
X-Cache: HIT from tproxy
X-Cache-Lookup: HIT from tproxy:3130
Via: 1.1 varnish, 1.1 tproxy (squid/4.6)
Connection: keep-alive
----------
2020/04/04 19:09:46.902 kid1| 17,2| FwdState.cc(678) handleUnregisteredServerEnd: self=0x5631ef5741d8*2 err=0 http://deb.debian.org/debian/pool/main/v/vim/vim_8.1.0875-5_amd64.deb
2020/04/04 19:09:46.919 kid1| 33,2| client_side.cc(582) swanSong: local=151.101.250.133:80 remote=192.168.111.55:47890 flags=33
_______________________________________________
squid-users mailing list
squid-users@lists.squid-cache.org
http://lists.squid-cache.org/listinfo/squid-users
