Re: [squid-users] TCP_REFRESH_UNMODIFIED instead of TCP_IMS_HIT? "Revalidation failed"

On 2/12/2011 2:29 a.m., David Wojak wrote:
> On 12/01/2011 01:42 PM, Amos Jeffries wrote:
>> On 2/12/2011 1:12 a.m., David Wojak wrote:
>>> On 11/30/2011 01:48 PM, David Wojak wrote:
>>>>
>>>>>
>>>>>> Client to Server (via proxy):
>>>>>>
>>>>>> GET
>>>>>> http://bla.bla.bla:8080/afdc3604/lib/commons-logging-1.1.1.jar
>>>>>> HTTP/1.1
>>>>>> Host: tlptest.m2n.at:8080
>>>>>> User-Agent: Mozilla/5.0 (X11; Linux x86_64; rv:8.0)
>>>>>> Gecko/20100101 Firefox/8.0
>>>>>> Accept:
>>>>>> text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8
>>>>>> Accept-Language: en-us,en;q=0.5
>>>>>> Accept-Encoding: gzip, deflate
>>>>>> Accept-Charset: ISO-8859-1,utf-8;q=0.7,*;q=0.7
>>>>>> Proxy-Connection: keep-alive
>>>>>> Cache-Control: no-cache
>>>>>>
>>>>>>
>>>>>> Proxy to origin server:
>>>>>>
>>>>>> GET /afdc3604/lib/commons-logging-1.1.1.jar HTTP/1.1
>>>>>> If-Modified-Since: Tue, 29 Nov 2011 12:21:04 GMT
>>>>>> Host: bla.bla.bla:8080
>>>>>> User-Agent: Mozilla/5.0 (X11; Linux x86_64; rv:8.0)
>>>>>> Gecko/20100101 Firefox/8.0
>>>>>> Accept:
>>>>>> text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8
>>>>>> Accept-Language: en-us,en;q=0.5
>>>>>> Accept-Encoding: gzip, deflate
>>>>>> Accept-Charset: ISO-8859-1,utf-8;q=0.7,*;q=0.7
>>>>>> Via: 1.1 proxytest (squid/3.1.16)
>>>>>> Cache-Control: max-age=5999940
>>>>>> Connection: keep-alive
>>>>>>
>>>>>>
>>>>>> Origin Server to Proxy:
>>>>>>
>>>>>> HTTP/1.1 304 Not Modified
>>>>>> Server: Jetty(6.1.16)
>>>>>
>>>>> There is no Date header here. Which may be a problem as it makes
>>>>> the 304 invalid, but Squid assumes "now" and sends that to the
>>>>> client...
>>>>
>>>> Well, thought of that too when I read the 304 specification...
>>>> well, I'll try that!
>>>>>
>>>>>>
>>>>>>
>>>>>> Proxy to client:
>>>>>>
>>>>>> HTTP/1.0 200 OK
>>>>>> Date: Wed, 30 Nov 2011 08:27:16 GMT
>>>>>> Content-Type: application/java-archive
>>>>>> Content-Length: 66245
>>>>>> Last-Modified: Tue, 29 Nov 2011 12:21:04 GMT
>>>>>> Server: Jetty(6.1.16)
>>>>>> Warning: 110 squid/3.1.16 "Response is stale", 111 squid/3.1.16
>>>>>> "Revalidation failed"
>>>>>> X-Cache: HIT from proxytest
>>>>>> X-Cache-Lookup: HIT from proxytest:3128
>>>>>> Via: 1.0 proxytest (squid/3.1.16)
>>>>>> Connection: keep-alive
>>>>>>
>>>>>
>>>>> I've been checking up. It appears the Warning bug is not fixed
>>>>> yet. It is wrong and can be ignored.
>>>>>
>>>>> If you can, fix that Date up though.
>>>>>
>>>>> Amos
>>>> Cool, thanks Amos! I'll try to fix the Date thingi on jetty-side.
>>>> I'll see if that makes a difference :)
>>>
>>> Amos, can you give me an example of how a valid IMS with valid 304
>>> response should look like? We changed the jetty header and tried
>>> again, but still - revalidation failed.
>>>
>>> Current Test:
>>>
>>> Client to proxy:
>>>
>>> GET http://bla.bla.bla:8080/3b8c257a/lib/commons-logging-1.1.1.jar
>>> HTTP/1.1
>>> Host: bla.bla.bla:8080
>>> User-Agent: Mozilla/5.0 (X11; Linux x86_64; rv:8.0) Gecko/20100101
>>> Firefox/8.0
>>> Accept: text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8
>>> Accept-Language: en-us,en;q=0.5
>>> Accept-Encoding: gzip, deflate
>>> Accept-Charset: ISO-8859-1,utf-8;q=0.7,*;q=0.7
>>> Proxy-Connection: keep-alive
>>> Cache-Control: no-cache
>>>
>>>
>>>
>>> Proxy to origin:
>>>
>>> GET /3b8c257a/lib/commons-logging-1.1.1.jar HTTP/1.1
>>> If-Modified-Since: Thu, 01 Dec 2011 10:25:55 GMT
>>> Host: bla.bla.bla:8080
>>> User-Agent: Mozilla/5.0 (X11; Linux x86_64; rv:8.0) Gecko/20100101
>>> Firefox/8.0
>>> Accept: text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8
>>> Accept-Language: en-us,en;q=0.5
>>> Accept-Encoding: gzip, deflate
>>> Accept-Charset: ISO-8859-1,utf-8;q=0.7,*;q=0.7
>>> Via: 1.1 proxytest (squid/3.1.16)
>>> Cache-Control: no-cache
>>> Connection: keep-alive
>>>
>>>
>>> Response:
>>>
>>> HTTP/1.1 304 Not Modified
>>> Date: Thu, 01 Dec 2011 11:05:59 GMT
>>> Server: Jetty(6.1.16)
>>>
>>> I've read something about "if you send cache-control with the get
>>> request, you have to send back the same header with the 304
>>> response" - but couldn't confirm that reading the RFCs... Any idea?
>>> What does squid need as response?
>>>
>>
>> What that is about is that *if* the 304 contains one of the valid
>> extra headers like Cache-Control, the Squid response is supposed to
>> be updated to contain the new information. Those are optional extras
>> which for now you are not using.
>>
>>>
>>> Proxy to client:
>>>
>>> HTTP/1.0 200 OK
>>> Content-Type: application/java-archive
>>> Content-Length: 66245
>>> Last-Modified: Thu, 01 Dec 2011 10:25:55 GMT
>>> Date: Thu, 01 Dec 2011 11:06:04 GMT
>>> Server: Jetty(6.1.16)
>>> Warning: 110 squid/3.1.16 "Response is stale", 111 squid/3.1.16
>>> "Revalidation failed"
>>> X-Cache: HIT from proxytest
>>> X-Cache-Lookup: HIT from proxytest:3128
>>> Via: 1.0 proxytest (squid/3.1.16)
>>> Connection: keep-alive
>>>
>>>
>>> and again in the log:
>>>
>>> 1322737561.457 9 192.168.100.215 TCP_REFRESH_UNMODIFIED/200
>>> 66658 GET
>>> http://bla.bla.bla:8080/3b8c257a/lib/commons-logging-1.1.1.jar -
>>> DIRECT/192.168.100.170 application/java-archive
>>>
>>
>> That is a success. The client is requesting a whole new copy, so
>> Squid is required to send a 200 with new copy. But is optimizing the
>> backend check to use 304.
>>
>> The warning is a minor bug, Squid is adding it based on the
>> before-validation information about the request.
>>
>> I was expecting Squid to update the Last-Modified date to the client
>> to say "Thu, 01 Dec 2011 11:05:59 GMT" from the 304, but will have to
>> double-check the code and RFCs about that.
>>
>> Amos
> I'm confused now... I guess I have a big understanding problem. Just
> to make sure: The "Date" header in the 304 response contains the Date
> of the server at the time the message was originated
> (http://www.w3.org/Protocols/rfc2616/rfc2616-sec14.html, "14.18
> Date"). So Squid performs fine - Last-Modified date should not be
> updated to "Thu, 01 Dec 2011 11:05:59 GMT".

Sorry. Yes on double-check I was wrong about LM changing. It was Date
header I was thinking of and Squid is updating it correctly.

>
> But the second thing I'm not sure about is the last part from the
> squid log: " - DIRECT/192.168.100.170 application/java-archive ".
> This means that the file the client will get (or got) is NOT from the
> cache, but from the origin server, right?

It means that server was contacted in order to service this request.
Nothing more. The re-validation counts as contacting the server.

The TCP_HIT/TCP_MISS/etc part of the log line indicates where the object
supplied came from (cache=*_HIT, or network=*_MISS, plus
revalidated=*_REFRESH_*). You have REFRESH_UNMODIFIED, which is a HIT
although for some reason the "HIT" is not actually stated in that type.
T`he Squid->client header "X-Cache: HIT from proxytest" make that clearer.

>
> Is there something wrong with my refresh_pattern? "refresh_pattern -i
> \.(jar)\??(.*?)$ 0 1% 99999 reload-into-ims refresh-ims". I also tried
> things like "0 100% 100" and "0 0% 0". But this makes no difference
> regarding the revalidation. It is stale or fresh when it should be -
> but if the GET request contains a "no-cache" or a "must-revalidate" an
> IMS is sent, a 304 comes back but I don't get the file from cache at
> any time.

No. The refresh_pattern numbers are the parameters of the staleness
estimation algorithm. It is only used when there is no Cache-Control or
Expires headers at all. In your case there is a Cache-Control and Squid
is obeying that must-revalidate. Squid has no need to calculate a guess
about when the revalidation is next to be performed.

>
> Would it make a difference if our jetty sends a "Cache-Control:
> must-revalidate" as response to a GET request? AND if we clear the
> Squid cache after making that change?
>
> I really think I'm doing something wrong here... oh, and thanks again
> for your time, Amos! I'm really desperate at the moment...
>

Relax, It appears to be working correctly in your last trace. Just some
misunderstanding about what the various bits mean.

Amos
Received on Thu Dec 01 2011 - 23:37:54 MST