[squid-users] A lot of TCP_REFRESH_UNMODIFIED after upgrading squid

Hello all, I got a strange behavior after I have upgraded squid from
2.6.STABLE21 to 3.3.5 on the parent proxy server.

I have a file in the cache

# zcat /var/log/squid/store.log-20130519.gz | grep 00000295
1368817711.745 SWAPOUT 00 00000295 83D4FBB382014271606DD58FADD64E98
200 1368817554 1368815579 -1 image/vnd.adobe.photoshop
635342245/635342245 GET
http://storage.example.net/b4bf4e39486f405346adbd09505767af-index_v2.psd

As we can see in the access log from main squid - first attempt from
client (192.168.204.208) was unsuccessful

# cat /var/log/squid/access-alt.log | grep b4bf4e39486f405346adbd09505767af
1368817711.751 158444 192.168.204.208 TCP_MISS/200 635342846 GET
http://storage.example.net/b4bf4e39486f405346adbd09505767af-index_v2.psd
- FIRST_PARENT_MISS/192.168.220.2 image/vnd.adobe.photoshop

and the file was downloaded directly from server
# zcat /var/log/squid/access.log-20130519.gz | grep
b4bf4e39486f405346adbd09505767af
1368817552.345 0 192.168.220.1 UDP_MISS/000 94 ICP_QUERY
http://storage.example.net/b4bf4e39486f405346adbd09505767af-index_v2.psd
- NONE/- -
1368817711.745 158442 192.168.220.1 TCP_MISS/200 635342769 GET
http://storage.example.net/b4bf4e39486f405346adbd09505767af-index_v2.psd
- DIRECT/205.251.242.180 image/vnd.adobe.photoshop

Later another client (192.168.203.121) trying to download the same
file and get hit in the parent cache.

1369057070.790 79814 192.168.203.121 TCP_MISS/200 635342857 GET
http://storage.example.net/b4bf4e39486f405346adbd09505767af-index_v2.psd
- PARENT_HIT/192.168.220.2 image/vnd.adobe.photoshop

So seems that everything work fine. Today after upgrading squid on the
parent from 2.6 to 3.3.5 I have tried again download the same file

# curl -v -O http://storage.example.net/b4bf4e39486f405346adbd09505767af-index_v2.psd
d* About to connect() to storage.example.net port 80 (#0)
* Trying xxx.xxx.xxx.198... connected
* Connected to storage.example.net (xxx.xxx.xxx.198) port 80 (#0)
> GET /b4bf4e39486f405346adbd09505767af-index_v2.psd HTTP/1.1
> User-Agent: curl/7.19.7 (x86_64-redhat-linux-gnu) libcurl/7.19.7 NSS/3.14.0.0 zlib/1.2.3 libidn/1.18 libssh2/1.4.2
> Host: storage.example.net
> Accept: */*
>
  % Total % Received % Xferd Average Speed Time Time Time Current
                                 Dload Upload Total Spent Left Speed
  0 0 0 0 0 0 0 0 --:--:-- 0:00:01
--:--:-- 0* HTTP 1.0, assume close after body
< HTTP/1.0 200 OK
< Last-Modified: Fri, 17 May 2013 18:32:59 GMT
< Accept-Ranges: bytes
< Content-Type: image/vnd.adobe.photoshop
< Content-Length: 635342245
< x-amz-id-2: +HuykoFgicH0hUFZQIBTU1AS8OZ7bN56vmcNxHz+1bYD8QOAwFseLuMQQElW4DZX
< x-amz-request-id: 63F9E75242B5C0B9
< Date: Sun, 26 May 2013 18:34:32 GMT
< ETag: "5b98acdf5929a2344aa9c3bbee870943"
< Server: AmazonS3
< Age: 0
< X-Cache: HIT from svn-parent.example.lan
< X-Cache-Lookup: HIT from svn-parent.example.lan:3128
< Via: 1.1 svn-parent.example.lan (squid/3.3.5)
< X-Cache: MISS from squid.example.lan
< X-Cache-Lookup: MISS from squid.example.lan:3129
< Connection: close
<
{ [data not shown]
100 605M 100 605M 0 0 82.9M 0 0:00:07 0:00:07
--:--:-- 110M* Closing connection #0

And in the log I see the following lines

main squid
1369593277.244 5787 192.168.210.102 TCP_MISS/200 635342835 GET
http://storage.example.net/b4bf4e39486f405346adbd09505767af-index_v2.psd
- FIRST_PARENT_MISS/192.168.220.2 image/vnd.adobe.photoshop

parent squid (3.3.5)
# cat /var/log/squid/access.log | grep b4bf4e39486f405346adbd09505767af
1369593271.465 0 192.168.220.1 UDP_MISS/000 94 ICP_QUERY
http://storage.psd2html.com/b4bf4e39486f405346adbd09505767af-index_v2.psd
- HIER_NONE/- -
1369593277.206 5741 192.168.220.1 TCP_REFRESH_UNMODIFIED/200
635342757 GET http://storage.psd2html.com/b4bf4e39486f405346adbd09505767af-index_v2.psd
- HIER_DIRECT/176.32.100.198 image/vnd.adobe.photoshop

As I understand from HIER_DIRECT/176.32.100.198 the file was
downloaded directly from server instead of local cache.

On the parent server I have the following refresh pattern

refresh_pattern \.psd$ 129600 100 129600 override-lastmod
override-expire ignore-reload
refresh_pattern \.zip$ 129600 100 129600 override-lastmod
override-expire ignore-reload
refresh_pattern \.rar$ 129600 100 129600 override-lastmod
override-expire ignore-reload

Did I miss something?

Thanks in advance
Received on Sun May 26 2013 - 19:00:58 MDT