[squid-users] TCP_REFRESH_HIT for FRESH object?

From: Denis Vlasenko <vda@dont-contact.us>
Date: Wed, 8 Jan 2003 15:48:46 +0200

Hi,

I continue to play with squid (squid-2.5.STABLE1-20021119).
Still a bit disappointed of low hit ratio.

I took this particular URL as a hacking target:
http://chat.ilyichevsk.net/chat/designes/super/love_style.css

I repeatedly get
TCP_REFRESH_HIT/304 231 GET http://.../love_style.css
(i.e. IMS does go to the origin server)
when it is accessed from chat page but it scores TCP_HIT
if I try to wget it or type url in fresh browser window.

I set debug_options to 22,3 , go to the chat room and I see:

access.log
==========
....
1042032016.022 584 172.16.42.177 TCP_REFRESH_HIT/304 231 GET http://chat.ilyichevsk.net/chat/designes/super/love_style.css
1042032016.730 2019 172.16.42.177 TCP_MISS/200 1348 GET http://chat.ilyichevsk.net/chat/alerter.php?
1042032037.552 31 172.16.42.177 TCP_HIT/200 426 GET http://chat.ilyichevsk.net/chat/faces/smile-normal.gif
1042032077.165 725 172.16.42.177 TCP_REFRESH_HIT/304 231 GET http://chat.ilyichevsk.net/chat/designes/super/love_style.css
1042032077.168 1239 172.16.42.177 TCP_MISS/200 1348 GET http://chat.ilyichevsk.net/chat/alerter.php?
1042032137.475 150 172.16.42.177 TCP_REFRESH_HIT/304 231 GET http://chat.ilyichevsk.net/chat/designes/super/love_style.css
1042032138.190 1002 172.16.42.177 TCP_MISS/200 1348 GET http://chat.ilyichevsk.net/chat/alerter.php?
1042032197.630 138 172.16.42.177 TCP_MISS/200 1348 GET http://chat.ilyichevsk.net/chat/alerter.php?
1042032197.716 121 172.16.42.177 TCP_REFRESH_HIT/304 231 GET http://chat.ilyichevsk.net/chat/designes/super/love_style.css
1042032205.560 253580 172.16.42.177 TCP_MISS/200 11108 GET http://chat.ilyichevsk.net/chat/tail.php?

(MISSes are okay, REFRESH_HITs are my worry)

But looking in cache.log, I see that actually love_style.css
is FRESH, not STALE as determined by refresh.c code!
It gets misreported in access.log or what?

cache.log
=========
....
2003/01/08 15:19:48| getMaxAge: 'http://chat.ilyichevsk.net/chat/who.php?session=679293c2df104ec7a35abe1f9c2b7fc4'
2003/01/08 15:19:48| ctx: enter level 0: 'http://chat.ilyichevsk.net/chat/who.php?session=679293c2df104ec7a35abe1f9c2b7fc4'
2003/01/08 15:19:48| refreshCheck: 'http://chat.ilyichevsk.net/chat/who.php?session=679293c2df104ec7a35abe1f9c2b7fc4'
2003/01/08 15:19:48| STALE: age 60 > min 0
2003/01/08 15:19:48| Staleness = 60
2003/01/08 15:19:48| refreshCheck: Matched '[?] 0 20% 864000'
2003/01/08 15:19:48| refreshCheck: age = 60
2003/01/08 15:19:48| check_time: Wed, 08 Jan 2003 13:20:48 GMT
2003/01/08 15:19:48| entry->timestamp: Wed, 08 Jan 2003 13:19:48 GMT
2003/01/08 15:19:48| ctx: exit level 0
2003/01/08 15:19:48| refreshCheck: 'http://chat.ilyichevsk.net/chat/designes/super/love_style.css'
2003/01/08 15:19:48| FRESH: age 1200 <= stale_age 2974518
2003/01/08 15:19:48| Staleness = -1
2003/01/08 15:19:48| refreshCheck: Matched '[.]css$ 86400 50% 864000'
2003/01/08 15:19:48| refreshCheck: age = 1200
2003/01/08 15:19:48| check_time: Wed, 08 Jan 2003 13:19:48 GMT
2003/01/08 15:19:48| entry->timestamp: Wed, 08 Jan 2003 12:59:48 GMT
2003/01/08 15:19:48| refreshCheck: YES: reload-into-ims
2003/01/08 15:19:48| getMaxAge: 'http://chat.ilyichevsk.net/chat/designes/super/love_style.css'
2003/01/08 15:19:49| refreshCheck: 'http://chat.ilyichevsk.net/chat/designes/love/images/privat.gif'
2003/01/08 15:19:49| FRESH: age 1202 <= stale_age 5368821
2003/01/08 15:19:49| Staleness = -1
2003/01/08 15:19:49| refreshCheck: Matched '[.]gif$ 86400 50% 864000'
2003/01/08 15:19:49| refreshCheck: age = 1202
2003/01/08 15:19:49| check_time: Wed, 08 Jan 2003 13:19:49 GMT
2003/01/08 15:19:49| entry->timestamp: Wed, 08 Jan 2003 12:59:47 GMT
2003/01/08 15:19:49| refreshCheck: YES: reload-into-ims
2003/01/08 15:19:49| refreshCheck: 'http://chat.ilyichevsk.net/chat/designes/love/images/eye.gif'
2003/01/08 15:19:49| FRESH: age 1202 <= stale_age 5368820
2003/01/08 15:19:49| Staleness = -1
2003/01/08 15:19:49| refreshCheck: Matched '[.]gif$ 86400 50% 864000'
2003/01/08 15:19:49| refreshCheck: age = 1202
2003/01/08 15:19:49| check_time: Wed, 08 Jan 2003 13:19:49 GMT
2003/01/08 15:19:49| entry->timestamp: Wed, 08 Jan 2003 12:59:47 GMT
2003/01/08 15:19:49| refreshCheck: YES: reload-into-ims
2003/01/08 15:19:49| getMaxAge: 'http://chat.ilyichevsk.net/chat/designes/love/images/privat.gif'
2003/01/08 15:19:49| getMaxAge: 'http://chat.ilyichevsk.net/chat/designes/love/images/eye.gif'
2003/01/08 15:19:49| refreshCheck: 'http://chat.ilyichevsk.net/chat/designes/love/images/status_0.gif'
2003/01/08 15:19:49| FRESH: age 1202 <= stale_age 5368819
2003/01/08 15:19:49| Staleness = -1
2003/01/08 15:19:49| refreshCheck: Matched '[.]gif$ 86400 50% 864000'
2003/01/08 15:19:49| refreshCheck: age = 1202
2003/01/08 15:19:49| check_time: Wed, 08 Jan 2003 13:19:49 GMT
2003/01/08 15:19:49| entry->timestamp: Wed, 08 Jan 2003 12:59:47 GMT
2003/01/08 15:19:49| refreshCheck: YES: reload-into-ims
2003/01/08 15:19:49| refreshCheck: 'http://chat.ilyichevsk.net/chat/designes/love/images/who_2ignor.gif'
2003/01/08 15:19:49| FRESH: age 1202 <= stale_age 5368819
2003/01/08 15:19:49| Staleness = -1
2003/01/08 15:19:49| refreshCheck: Matched '[.]gif$ 86400 50% 864000'
2003/01/08 15:19:49| refreshCheck: age = 1202
2003/01/08 15:19:49| check_time: Wed, 08 Jan 2003 13:19:49 GMT
2003/01/08 15:19:49| entry->timestamp: Wed, 08 Jan 2003 12:59:47 GMT
2003/01/08 15:19:49| refreshCheck: YES: reload-into-ims
2003/01/08 15:19:49| getMaxAge: 'http://chat.ilyichevsk.net/chat/designes/love/images/status_0.gif'
2003/01/08 15:19:49| getMaxAge: 'http://chat.ilyichevsk.net/chat/designes/love/images/who_2ignor.gif'
2003/01/08 15:19:49| refreshCheck: 'http://chat.ilyichevsk.net/chat/designes/love/images/gender_girl.gif'
2003/01/08 15:19:49| FRESH: age 1202 <= stale_age 5368820
2003/01/08 15:19:49| Staleness = -1
2003/01/08 15:19:49| refreshCheck: Matched '[.]gif$ 86400 50% 864000'
2003/01/08 15:19:49| refreshCheck: age = 1202
2003/01/08 15:19:49| check_time: Wed, 08 Jan 2003 13:19:49 GMT
2003/01/08 15:19:49| entry->timestamp: Wed, 08 Jan 2003 12:59:47 GMT
2003/01/08 15:19:49| refreshCheck: YES: reload-into-ims
2003/01/08 15:19:49| refreshCheck: 'http://chat.ilyichevsk.net/chat/designes/love/images/info.gif'
2003/01/08 15:19:49| FRESH: age 1202 <= stale_age 5368820
2003/01/08 15:19:49| Staleness = -1
2003/01/08 15:19:49| refreshCheck: Matched '[.]gif$ 86400 50% 864000'
2003/01/08 15:19:49| refreshCheck: age = 1202
2003/01/08 15:19:49| check_time: Wed, 08 Jan 2003 13:19:49 GMT
2003/01/08 15:19:49| entry->timestamp: Wed, 08 Jan 2003 12:59:47 GMT
2003/01/08 15:19:49| refreshCheck: YES: reload-into-ims
2003/01/08 15:19:49| getMaxAge: 'http://chat.ilyichevsk.net/chat/designes/love/images/gender_girl.gif'
2003/01/08 15:19:49| getMaxAge: 'http://chat.ilyichevsk.net/chat/designes/love/images/info.gif'
2003/01/08 15:19:49| refreshCheck: 'http://chat.ilyichevsk.net/chat/designes/love/images/gender_boy.gif'
2003/01/08 15:19:49| FRESH: age 1202 <= stale_age 5368820
2003/01/08 15:19:49| Staleness = -1
2003/01/08 15:19:49| refreshCheck: Matched '[.]gif$ 86400 50% 864000'
2003/01/08 15:19:49| refreshCheck: age = 1202
2003/01/08 15:19:49| check_time: Wed, 08 Jan 2003 13:19:49 GMT
2003/01/08 15:19:49| entry->timestamp: Wed, 08 Jan 2003 12:59:47 GMT
2003/01/08 15:19:49| refreshCheck: YES: reload-into-ims
2003/01/08 15:19:49| getMaxAge: 'http://chat.ilyichevsk.net/chat/designes/love/images/gender_boy.gif'
2003/01/08 15:19:51| refreshCheck: 'http://chat.ilyichevsk.net/chat/designes/love/images/status_3.gif'
2003/01/08 15:19:51| FRESH: age 1203 <= stale_age 5368820
2003/01/08 15:19:51| Staleness = -1
2003/01/08 15:19:51| refreshCheck: Matched '[.]gif$ 86400 50% 864000'
2003/01/08 15:19:51| refreshCheck: age = 1203
2003/01/08 15:19:51| check_time: Wed, 08 Jan 2003 13:19:51 GMT
2003/01/08 15:19:51| entry->timestamp: Wed, 08 Jan 2003 12:59:48 GMT
2003/01/08 15:19:51| refreshCheck: YES: reload-into-ims
2003/01/08 15:19:51| getMaxAge: 'http://chat.ilyichevsk.net/chat/designes/love/images/status_3.gif'
2003/01/08 15:20:15| getMaxAge: 'http://chat.ilyichevsk.net/chat/alerter.php?session=679293c2df104ec7a35abe1f9c2b7fc4'
2003/01/08 15:20:15| ctx: enter level 0: 'http://chat.ilyichevsk.net/chat/alerter.php?session=679293c2df104ec7a35abe1f9c2b7fc4'
2003/01/08 15:20:15| refreshCheck: 'http://chat.ilyichevsk.net/chat/alerter.php?session=679293c2df104ec7a35abe1f9c2b7fc4'
2003/01/08 15:20:15| STALE: age 60 > min 0
2003/01/08 15:20:15| Staleness = 60
2003/01/08 15:20:15| refreshCheck: Matched '[?] 0 20% 864000'
2003/01/08 15:20:15| refreshCheck: age = 60
2003/01/08 15:20:15| check_time: Wed, 08 Jan 2003 13:21:15 GMT
2003/01/08 15:20:15| entry->timestamp: Wed, 08 Jan 2003 13:20:15 GMT
2003/01/08 15:20:15| ctx: exit level 0
2003/01/08 15:20:15| refreshCheck: 'http://chat.ilyichevsk.net/chat/designes/super/love_style.css'
2003/01/08 15:20:15| FRESH: age 27 <= stale_age 2975118
2003/01/08 15:20:15| Staleness = -1
2003/01/08 15:20:15| refreshCheck: Matched '[.]css$ 86400 50% 864000'
2003/01/08 15:20:15| refreshCheck: age = 27
2003/01/08 15:20:15| check_time: Wed, 08 Jan 2003 13:20:15 GMT
2003/01/08 15:20:15| entry->timestamp: Wed, 08 Jan 2003 13:19:48 GMT
2003/01/08 15:20:15| refreshCheck: YES: reload-into-ims
2003/01/08 15:20:15| getMaxAge: 'http://chat.ilyichevsk.net/chat/designes/super/love_style.css'
2003/01/08 15:20:37| refreshCheck: 'http://chat.ilyichevsk.net/chat/faces/smile-normal.gif'
2003/01/08 15:20:37| FRESH: age 4176 <= stale_age 5474337
2003/01/08 15:20:37| Staleness = -1
2003/01/08 15:20:37| refreshCheck: Matched '[.]gif$ 86400 50% 864000'
2003/01/08 15:20:37| refreshCheck: age = 4176
2003/01/08 15:20:37| check_time: Wed, 08 Jan 2003 13:20:37 GMT
2003/01/08 15:20:37| entry->timestamp: Wed, 08 Jan 2003 12:11:01 GMT
2003/01/08 15:21:16| getMaxAge: 'http://chat.ilyichevsk.net/chat/alerter.php?session=679293c2df104ec7a35abe1f9c2b7fc4'
2003/01/08 15:21:16| ctx: enter level 0: 'http://chat.ilyichevsk.net/chat/alerter.php?session=679293c2df104ec7a35abe1f9c2b7fc4'
2003/01/08 15:21:16| refreshCheck: 'http://chat.ilyichevsk.net/chat/alerter.php?session=679293c2df104ec7a35abe1f9c2b7fc4'
2003/01/08 15:21:16| STALE: age 60 > min 0
2003/01/08 15:21:16| Staleness = 60
2003/01/08 15:21:16| refreshCheck: Matched '[?] 0 20% 864000'
2003/01/08 15:21:16| refreshCheck: age = 60
2003/01/08 15:21:16| check_time: Wed, 08 Jan 2003 13:22:16 GMT
2003/01/08 15:21:16| entry->timestamp: Wed, 08 Jan 2003 13:21:16 GMT
2003/01/08 15:21:16| ctx: exit level 0
2003/01/08 15:21:16| refreshCheck: 'http://chat.ilyichevsk.net/chat/designes/super/love_style.css'
2003/01/08 15:21:16| FRESH: age 61 <= stale_age 2975132
2003/01/08 15:21:16| Staleness = -1
2003/01/08 15:21:16| refreshCheck: Matched '[.]css$ 86400 50% 864000'
2003/01/08 15:21:16| refreshCheck: age = 61
2003/01/08 15:21:16| check_time: Wed, 08 Jan 2003 13:21:16 GMT
2003/01/08 15:21:16| entry->timestamp: Wed, 08 Jan 2003 13:20:15 GMT
2003/01/08 15:21:16| refreshCheck: YES: reload-into-ims
2003/01/08 15:21:16| getMaxAge: 'http://chat.ilyichevsk.net/chat/designes/super/love_style.css'
2003/01/08 15:22:17| getMaxAge: 'http://chat.ilyichevsk.net/chat/alerter.php?session=679293c2df104ec7a35abe1f9c2b7fc4'
2003/01/08 15:22:17| ctx: enter level 0: 'http://chat.ilyichevsk.net/chat/alerter.php?session=679293c2df104ec7a35abe1f9c2b7fc4'
2003/01/08 15:22:17| refreshCheck: 'http://chat.ilyichevsk.net/chat/alerter.php?session=679293c2df104ec7a35abe1f9c2b7fc4'
2003/01/08 15:22:17| STALE: age 60 > min 0
2003/01/08 15:22:17| Staleness = 60
2003/01/08 15:22:17| refreshCheck: Matched '[?] 0 20% 864000'
2003/01/08 15:22:17| refreshCheck: age = 60
2003/01/08 15:22:17| check_time: Wed, 08 Jan 2003 13:23:17 GMT
2003/01/08 15:22:17| entry->timestamp: Wed, 08 Jan 2003 13:22:17 GMT
2003/01/08 15:22:17| ctx: exit level 0
2003/01/08 15:22:17| refreshCheck: 'http://chat.ilyichevsk.net/chat/designes/super/love_style.css'
2003/01/08 15:22:17| FRESH: age 60 <= stale_age 2975163
2003/01/08 15:22:17| Staleness = -1
2003/01/08 15:22:17| refreshCheck: Matched '[.]css$ 86400 50% 864000'
2003/01/08 15:22:17| refreshCheck: age = 60
2003/01/08 15:22:17| check_time: Wed, 08 Jan 2003 13:22:17 GMT
2003/01/08 15:22:17| entry->timestamp: Wed, 08 Jan 2003 13:21:17 GMT
2003/01/08 15:22:17| refreshCheck: YES: reload-into-ims
2003/01/08 15:22:17| getMaxAge: 'http://chat.ilyichevsk.net/chat/designes/super/love_style.css'
2003/01/08 15:23:17| getMaxAge: 'http://chat.ilyichevsk.net/chat/alerter.php?session=679293c2df104ec7a35abe1f9c2b7fc4'
2003/01/08 15:23:17| ctx: enter level 0: 'http://chat.ilyichevsk.net/chat/alerter.php?session=679293c2df104ec7a35abe1f9c2b7fc4'
2003/01/08 15:23:17| refreshCheck: 'http://chat.ilyichevsk.net/chat/alerter.php?session=679293c2df104ec7a35abe1f9c2b7fc4'
2003/01/08 15:23:17| STALE: age 60 > min 0
2003/01/08 15:23:17| Staleness = 60
2003/01/08 15:23:17| refreshCheck: Matched '[?] 0 20% 864000'
2003/01/08 15:23:17| refreshCheck: age = 60
2003/01/08 15:23:17| check_time: Wed, 08 Jan 2003 13:24:17 GMT
2003/01/08 15:23:17| entry->timestamp: Wed, 08 Jan 2003 13:23:17 GMT
2003/01/08 15:23:17| ctx: exit level 0
2003/01/08 15:23:17| refreshCheck: 'http://chat.ilyichevsk.net/chat/designes/super/love_style.css'
2003/01/08 15:23:17| FRESH: age 60 <= stale_age 2975193
2003/01/08 15:23:17| Staleness = -1
2003/01/08 15:23:17| refreshCheck: Matched '[.]css$ 86400 50% 864000'
2003/01/08 15:23:17| refreshCheck: age = 60
2003/01/08 15:23:17| check_time: Wed, 08 Jan 2003 13:23:17 GMT
2003/01/08 15:23:17| entry->timestamp: Wed, 08 Jan 2003 13:22:17 GMT
2003/01/08 15:23:17| refreshCheck: YES: reload-into-ims
2003/01/08 15:23:17| getMaxAge: 'http://chat.ilyichevsk.net/chat/designes/super/love_style.css'

--
vda
Received on Wed Jan 08 2003 - 06:55:05 MST

This archive was generated by hypermail pre-2.1.9 : Tue Dec 09 2003 - 17:12:35 MST