[squid-users] Explaining RELEASEs

From: Yang Zhang <yanghatespam_at_gmail.com>
Date: Fri, 15 Apr 2011 19:12:33 -0700

We're seeing a bunch of the following pairs of RELEASE/SWAPOUT lines
for the same URL in our store.log. Can anyone help me understand
what's happening here?

1302893424.155 RELEASE 00 000830A0 6E5CACCDB20F6654643A090ACC1B995D
200 1302893423 -1 -1 application/json 2058/2058 GET
http://foo.com/alpha
1302893424.155 SWAPOUT 00 000830A2 6E5CACCDB20F6654643A090ACC1B995D
200 1302893424 -1 -1 application/json 2058/2058 GET
http://foo.com/alpha
1302893424.332 RELEASE 00 000830A4 28E57991079BA357DCD9AA6C8D435A57
200 1302893424 -1 -1 application/json 2057/2057 GET
http://foo.com/beta
1302893424.333 SWAPOUT 00 000830A6 28E57991079BA357DCD9AA6C8D435A57
200 1302893424 -1 -1 application/json 2057/2057 GET
http://foo.com/beta

Our squid.conf should aggressively cache everything forever, since
we're using squid as an application cache against remote web services:

  # Increased disk cache size to 5GB; currently consuming 2.8GB
  cache_dir ufs /var/spool/squid3 5000 16 256
  ...
  # Cache everything, forever
  refresh_pattern . 525600 100% 525600 override-expire ignore-private ignore-n

So I don't understand why there are RELEASEs happening at all - I
assume that means . If I also interleave lines from access.log:

1302893423.974 SWAPOUT 00 000830A0 6E5CACCDB20F6654643A090ACC1B995D
200 1302893423 -1 -1 application/json 2058/2058 GET
http://foo.com/alpha
1302893423.975 255 10.160.227.224 TCP_MISS/200 2372 GET
http://foo.com/alpha - DIRECT/173.223.232.122 application/json
...
1302893424.155 RELEASE 00 000830A0 6E5CACCDB20F6654643A090ACC1B995D
200 1302893423 -1 -1 application/json 2058/2058 GET
http://foo.com/alpha
1302893424.155 SWAPOUT 00 000830A2 6E5CACCDB20F6654643A090ACC1B995D
200 1302893424 -1 -1 application/json 2058/2058 GET
http://foo.com/alpha
1302893424.183 466 10.160.227.224 TCP_MISS/200 2372 GET
http://foo.com/alpha - DIRECT/173.223.232.122 application/json
1302894993.280 8 10.160.227.224 TCP_MEM_HIT/200 2381 GET
http://foo.com/alpha - NONE/- application/json
1302894993.280 8 10.160.227.224 TCP_MEM_HIT/200 2381 GET
http://foo.com/alpha - NONE/- application/json

My interpretation is:

- the first 2 lines (at time ...23) are for the initial fetch, which
saved to disk then recorded as a miss in access.log. All good so far.

- the next access of this URL (at time ...24) results in a...release
and miss. This is what surprises me.

- then subsequent accesses work (hits in memory)

Just trying to gain some transparency into squid's decision-making
here. Thanks.

-- 
Yang Zhang
http://yz.mit.edu/
Received on Sat Apr 16 2011 - 02:12:59 MDT

This archive was generated by hypermail 2.2.0 : Sat Apr 16 2011 - 12:00:04 MDT