Re: possible squid bugs [was: cacheability engine]

On Wed, 22 Mar 2000, Mark Nottingham wrote:
 
> Any more thoughts about this? If you'd like, I'll do it against a 'normal'
> (non-surrogate/reverse/whatever) host, and submit to squid-bugs...

I spent quite a bit of time with this on Friday and Sautrday.
So, I have some thoughts now.

Squid's problem seems to be that we're overloading the 'timestamp'
member of StoreEntry. In some cases we use it as the time
of last validation. Other places we use it as the time
the response was generated.

Obviously we have to stop overloading 'timestamp'.
It either needs to be the "served date" or the last validation
time. Here's some options:

1) timestamp becomes 'last valid' date. To get the served date we
   parse HTTP headers on cache hits (we do this already). problem is
   that about 10% of all responses dont have a Date header.

2) timestamp becomes served date. We need to store last valid date
   somewhere. We can probably change entry->lastmod to
   entry->lastvalid. In this case, we get last modification time from
   parsed headers on cache hits. This means the content of people's
   existing swap.state and swap file headers (meta data) is going to be
   wrong.

I played around with the 2.4 code and removed 'expires' from StoreEntry
and replaced 'lastmod' with 'lastvalid'. This makes the StoreEntry
smaller, but also makes it incompatible with current caches. Anyway,
it seems to work okay. I think we can stop storing lastmodified
time in StoreEntry and store lastvalid time instead.

Duane W.

> On Wed, Feb 09, 2000 at 11:50:07AM -0800, Mark Nottingham wrote:
> >
> > I was using 2.2STABLE5; retested with 2.3STABLE1, and found similar
> > behaviour. The Age header is stripped from the MISS, but hits still have an
> > erroneous Age associated with them; it doesn't follow the rules in RFC2616.
> >
> > Also, as you can see, the refresh factor is being calculated in different
> > ways, based on the context of the hit; as a result, it dropd from over 600
> > to a very small number. I think this is happening because the timestamp is
> > first populated with the Date header value, and later replaced with
> > squid_curtime...
> >
> > cheers,
> >
> >
> >
> > *** 1
> >
> > > GET http://a516.g.akamai.net:80/7/516/1/c7aecd2ab69dae/www.akamai.com/images/i
> > village_logo2.jpg HTTP/1.0
> > > User-Agent: Wget/1.5.3
> > > Host: a516.g.akamai.net:80
> > > Accept: */*
> >
> > 950123425.362 1:1 277 127.0.0.1:2561 < 127.0.0.1:3128
> > < HTTP/1.0 200 OK
> > < Server: Netscape-Enterprise/3.6 SP2
> > < Date: Tue, 08 Feb 2000 19:35:24 GMT
> > < Content-Type: image/jpeg
> > < Last-Modified: Tue, 08 Feb 2000 19:33:11 GMT
> > < Content-Length: 3057
> > < Accept-Ranges: bytes
> > < X-Cache: MISS from dhcp2-54.west.akamai.com
> > < Proxy-Connection: close
> >
> > 950123425.398 89 127.0.0.1 TCP_MISS/200 3336 GET http://a516.g.akamai.net/7/516/1/c7aecd2ab69dae/www.akamai.com/images/ivillage_logo2.jpg - DIRECT/a516.g.akamai.net image/jpeg
> >
> > 2000/02/09 11:10:25| refreshCheck(On Store): 'http://a516.g.akamai.net/7/516/1/c7aecd2ab69dae/www.akamai.com/images/ivillage_logo2.jpg'
> > 2000/02/09 11:10:25| refreshCheck: Matched '. 0 20% 259200'
> > 2000/02/09 11:10:25| refreshCheck: age = 84961
> > 2000/02/09 11:10:25| check_time: Wed, 09 Feb 2000 19:11:25 GMT
> > 2000/02/09 11:10:25| entry->timestamp: Tue, 08 Feb 2000 19:35:24 GMT
> > 2000/02/09 11:10:25| refreshCheck: factor = 638.804511
> > 2000/02/09 11:10:25| refreshCheck: YES: factor >= pct
> >
> >
> > *** 2
> >
> > 950123441.785 2:1 171 127.0.0.1:2564 > 127.0.0.1:3128
> > > GET http://a516.g.akamai.net:80/7/516/1/c7aecd2ab69dae/www.akamai.com/images/i
> > village_logo2.jpg HTTP/1.0
> > > User-Agent: Wget/1.5.3
> > > Host: a516.g.akamai.net:80
> > > Accept: */*
> >
> > 950123441.841 2:1 276 127.0.0.1:2564 < 127.0.0.1:3128
> > < HTTP/1.0 200 OK
> > < Server: Netscape-Enterprise/3.6 SP2
> > < Date: Tue, 08 Feb 2000 19:35:24 GMT
> > < Content-Type: image/jpeg
> > < Last-Modified: Tue, 08 Feb 2000 19:33:11 GMT
> > < Content-Length: 3057
> > < Accept-Ranges: bytes
> > < X-Cache: HIT from dhcp2-54.west.akamai.com
> > < Proxy-Connection: close
> >
> > 950123441.840 55 127.0.0.1 TCP_REFRESH_HIT/200 3335 GET http://a516.g.akamai.net/7/516/1/c7aecd2ab69dae/www.akamai.com/images/ivillage_logo2.jpg - DIRECT/a516.g.akamai.net image/jpeg
> >
> > 2000/02/09 11:10:41| refreshCheck(HTTP): 'http://a516.g.akamai.net/7/516/1/c7aecd2ab69dae/www.akamai.com/images/ivillage_logo2.jpg'
> > 2000/02/09 11:10:41| refreshCheck: Matched '. 0 20% 259200'
> > 2000/02/09 11:10:41| refreshCheck: age = 84917
> > 2000/02/09 11:10:41| check_time: Wed, 09 Feb 2000 19:10:41 GMT
> > 2000/02/09 11:10:41| entry->timestamp: Tue, 08 Feb 2000 19:35:24 GMT
> > 2000/02/09 11:10:41| refreshCheck: factor = 638.473684
> > 2000/02/09 11:10:41| refreshCheck: YES: factor >= pct
> >
> >
> > *** 3
> >
> > 950123463.263 3:1 171 127.0.0.1:2567 > 127.0.0.1:3128
> > > GET http://a516.g.akamai.net:80/7/516/1/c7aecd2ab69dae/www.akamai.com/images/i
> > village_logo2.jpg HTTP/1.0
> > > User-Agent: Wget/1.5.3
> > > Host: a516.g.akamai.net:80
> > > Accept: */*
> >
> > 950123463.269 3:1 285 127.0.0.1:2567 < 127.0.0.1:3128
> > < HTTP/1.0 200 OK
> > < Server: Netscape-Enterprise/3.6 SP2
> > < Date: Tue, 08 Feb 2000 19:35:24 GMT
> > < Content-Type: image/jpeg
> > < Last-Modified: Tue, 08 Feb 2000 19:33:11 GMT
> > < Content-Length: 3057
> > < Accept-Ranges: bytes
> > < Age: 22
> > < X-Cache: HIT from dhcp2-54.west.akamai.com
> > < Proxy-Connection: close
> >
> > 950123463.267 4 127.0.0.1 TCP_MEM_HIT/200 3344 GET http://a516.g.akamai.net/7/516/1/c7aecd2ab69dae/www.akamai.com/images/ivillage_logo2.jpg - NONE/- image/jpeg
> >
> > 2000/02/09 11:11:03| refreshCheck(HTTP): 'http://a516.g.akamai.net/7/516/1/c7aecd2ab69dae/www.akamai.com/images/ivillage_logo2.jpg'
> > 2000/02/09 11:11:03| refreshCheck: Matched '. 0 20% 259200'
> > 2000/02/09 11:11:03| refreshCheck: age = 22
> > 2000/02/09 11:11:03| check_time: Wed, 09 Feb 2000 19:11:03 GMT
> > 2000/02/09 11:11:03| entry->timestamp: Wed, 09 Feb 2000 19:10:41 GMT
> > 2000/02/09 11:11:03| refreshCheck: factor = 0.000259
> > 2000/02/09 11:11:03| refreshCheck: NO: factor < pct
> >
> >
> > *** 4
> >
> > 950123471.653 4:1 171 127.0.0.1:2569 > 127.0.0.1:3128
> > > GET http://a516.g.akamai.net:80/7/516/1/c7aecd2ab69dae/www.akamai.com/images/i
> > village_logo2.jpg HTTP/1.0
> > > User-Agent: Wget/1.5.3
> > > Host: a516.g.akamai.net:80
> > > Accept: */*
> >
> > 950123471.658 4:1 285 127.0.0.1:2569 < 127.0.0.1:3128
> > < HTTP/1.0 200 OK
> > < Server: Netscape-Enterprise/3.6 SP2
> > < Date: Tue, 08 Feb 2000 19:35:24 GMT
> > < Content-Type: image/jpeg
> > < Last-Modified: Tue, 08 Feb 2000 19:33:11 GMT
> > < Content-Length: 3057
> > < Accept-Ranges: bytes
> > < Age: 30
> > < X-Cache: HIT from dhcp2-54.west.akamai.com
> > < Proxy-Connection: close
> >
> > 950123471.657 4 127.0.0.1 TCP_MEM_HIT/200 3344 GET http://a516.g.akamai.net/7/516/1/c7aecd2ab69dae/www.akamai.com/images/ivillage_logo2.jpg - NONE/- image/jpeg
> >
> > 2000/02/09 11:11:11| refreshCheck(HTTP): 'http://a516.g.akamai.net/7/516/1/c7aecd2ab69dae/www.akamai.com/images/ivillage_logo2.jpg'
> > 2000/02/09 11:11:11| refreshCheck: Matched '. 0 20% 259200'
> > 2000/02/09 11:11:11| refreshCheck: age = 30
> > 2000/02/09 11:11:11| check_time: Wed, 09 Feb 2000 19:11:11 GMT
> > 2000/02/09 11:11:11| entry->timestamp: Wed, 09 Feb 2000 19:10:41 GMT
> > 2000/02/09 11:11:11| refreshCheck: factor = 0.000353
> > 2000/02/09 11:11:11| refreshCheck: NO: factor < pct
> >
> >
> >
> >
> >
> > 950123924.929 5:1 171 127.0.0.1:2575 > 127.0.0.1:3128
> > > GET http://a516.g.akamai.net:80/7/516/1/c7aecd2ab69dae/www.akamai.com/images/ivillage_logo2.jpg HTTP/1.0
> > > User-Agent: Wget/1.5.3
> > > Host: a516.g.akamai.net:80
> > > Accept: */*
> >
> > 950123924.939 5:1 286 127.0.0.1:2575 < 127.0.0.1:3128
> > < HTTP/1.0 200 OK
> > < Server: Netscape-Enterprise/3.6 SP2
> > < Date: Tue, 08 Feb 2000 19:35:24 GMT
> > < Content-Type: image/jpeg
> > < Last-Modified: Tue, 08 Feb 2000 19:33:11 GMT
> > < Content-Length: 3057
> > < Accept-Ranges: bytes
> > < Age: 483
> > < X-Cache: HIT from dhcp2-54.west.akamai.com
> > < Proxy-Connection: close
> >
> > 950123924.937 8 127.0.0.1 TCP_MEM_HIT/200 3345 GET http://a516.g.akamai.net/7/516/1/c7aecd2ab69dae/www.akamai.com/images/ivillage_logo2.jpg - NONE/- image/jpeg
> >
> > 2000/02/09 11:18:44| refreshCheck(HTTP): 'http://a516.g.akamai.net/7/516/1/c7aecd2ab69dae/www.akamai.com/images/ivillage_logo2.jpg'
> > 2000/02/09 11:18:44| refreshCheck: Matched '. 0 20% 259200'
> > 2000/02/09 11:18:44| refreshCheck: age = 483
> > 2000/02/09 11:18:44| check_time: Wed, 09 Feb 2000 19:18:44 GMT
> > 2000/02/09 11:18:44| entry->timestamp: Wed, 09 Feb 2000 19:10:41 GMT
> > 2000/02/09 11:18:44| refreshCheck: factor = 0.005679
> > 2000/02/09 11:18:44| refreshCheck: NO: factor < pct
> >
> >
> >
> >
> >
> >
> >
> >
> > --
> > Mark Nottingham, Senior Developer
> > Akamai Technologies (San Mateo, CA)
>
> --
> Mark Nottingham, Senior Developer
> Akamai Technologies (San Mateo, CA)
>
Received on Mon Mar 27 2000 - 14:30:24 MST