Squid Reverse Proxy (accel) always contacting the server

[Daniele Segato <daniele.segato@xxxxxxxxx>]

Hi,

This is what I want to obtain:

Environment:
* everything on the same machine (Debian GNU\Linux)
* server running on tomcat, port 8080
* squid running on port 280
* client can be anywhere, but for now it's on the localhost machine too

I want to set up an http cache to my tomcat server to reduce the load on it.

And I expect to obtain a result like this:

First request
1. 9:00 AM (today) client request GET to http://localhost:280/myservice
2. squid receive the request, nothing in cache, contact my server
3. tomcat reply with a 200, the body and some header:
Cache-Control: public, max-age=3600
Last-Modified: //8:00 AM//
4. squid store in cache that result that should be valid until 10:00 AM 
(today) = 9:00 AM (time of the request) + 3600 seconds (max-age)
5. client receive the response

Second request:
1. 9:05 AM (today) client request GET to http://localhost:280/myservice 
with header
If-Modified-Since: //8:00 AM//
2. squid receive the request, see 9:05 AM < 10:00 AM --> cache hit 304
3. client receive the response 304

Third request (after 10:00 AM)
1. 10:05 AM (today) client request GET to 
http://localhost:280/myservicewith header
If-Modified-Since: //8:00 AM//
2. squid receive the request, see 10:05 AM > 10:00 AM --> time to see if 
the server has a new version, forward the if-modified-since request to 
the server
3. suppose the resource is not changed: tomcat reply with a 304 Not 
Modified, again with headers:
Cache-Control: public, max-age=3600
Last-Modified: //8:00 AM//
4. squid store update the cache value to be valid until 11:05 AM (today) 
= 10:05 AM (time of the request) + 3600 seconds (max-age)
5. client receive the response: 304 Not Modified



Instead squid is ALWAYS requiring the resource to the server:
$ curl -v -H 'If-Modified-Since: Thu, 29 Mar 2012 22:14:20 GMT' 
'http://localhost:280/alfresco/service/catalog/products'

* About to connect() to localhost port 280 (#0)
*   Trying 127.0.0.1...
* connected
* Connected to localhost (127.0.0.1) port 280 (#0)
> GET /alfresco/service/catalog/products HTTP/1.1
> User-Agent: curl/7.24.0 (x86_64-pc-linux-gnu) libcurl/7.24.0
OpenSSL/1.0.0h zlib/1.2.6 libidn/1.24 libssh2/1.2.8 librtmp/2.3
> Host: localhost:280
> Accept: */*
> If-Modified-Since: Thu, 29 Mar 2012 22:14:20 GMT
* additional stuff not fine transfer.c:1037: 0 0
* HTTP 1.0, assume close after body
< HTTP/1.0 304 Not Modified
< Date: Thu, 29 Mar 2012 23:27:57 GMT
< Cache-Control: public,  max-age=3600
< Last-Modified: Thu, 29 Mar 2012 22:14:20 GMT
< Content-Type: application/json;charset=UTF-8
< Content-Length: 1158
< Server: Jetty(6.1.21)
< Age: 1
< X-Cache: HIT from localhost
< X-Cache-Lookup: HIT from localhost:280
< Via: 1.0 localhost (squid/3.1.19)
* HTTP/1.0 connection set to keep alive!
< Connection: keep-alive
<
* Connection #0 to host localhost left intact
* Closing connection #0


It say X-Cache: HIT

but I actually see the log in my server: the request is reaching it.
And since I have to do all the job but the rendering to check if the 
content is changed this create an heavy load on the server.



Here my configuration:

the /etc/squid3/squid.conf (only added include on the top)

include /etc/squid3/accel8080.conf
acl manager proto cache_object
acl localhost src 127.0.0.1/32 ::1
acl to_localhost dst 127.0.0.0/8 0.0.0.0/32 ::1
acl SSL_ports port 443
acl Safe_ports port 80		# http
acl Safe_ports port 21		# ftp
acl Safe_ports port 443		# https
acl Safe_ports port 70		# gopher
acl Safe_ports port 210		# wais
acl Safe_ports port 1025-65535	# unregistered ports
acl Safe_ports port 280		# http-mgmt
acl Safe_ports port 488		# gss-http
acl Safe_ports port 591		# filemaker
acl Safe_ports port 777		# multiling http
acl CONNECT method CONNECT
http_access allow manager localhost
http_access deny manager
http_access deny !Safe_ports
http_access deny CONNECT !SSL_ports
http_access allow localhost
http_access deny all
http_port 3128
coredump_dir /var/spool/squid3
refresh_pattern ^ftp:		1440	20%	10080
refresh_pattern ^gopher:	1440	0%	1440
refresh_pattern -i (/cgi-bin/|\?) 0	0%	0
refresh_pattern .		0	20%	4320


the included config file (my custom reverse proxy conf):

http_port localhost:280 accel ignore-cc
cache_peer 127.0.0.1 parent 8080 0 no-query originserver no-digest 
default name=myAccel
refresh_all_ims off
acl Safe_ports port 280
http_access deny !Safe_ports
acl our_sites dstdomain 127.0.0.1
acl our_sites dstdomain localhost
http_access allow our_sites
cache_peer_access myAccel allow our_sites
cache_peer_access myAccel deny all




The startup log (cache.log):

2012/03/30 01:32:22| Starting Squid Cache version 3.1.19 for 
x86_64-pc-linux-gnu...
2012/03/30 01:32:22| Process ID 23466
2012/03/30 01:32:22| With 65535 file descriptors available
2012/03/30 01:32:22| Initializing IP Cache...
2012/03/30 01:32:22| DNS Socket created at [::], FD 7
2012/03/30 01:32:22| DNS Socket created at 0.0.0.0, FD 8
2012/03/30 01:32:22| Adding nameserver 192.168.88.254 from /etc/resolv.conf
2012/03/30 01:32:22| Adding nameserver 192.168.1.1 from /etc/resolv.conf
2012/03/30 01:32:22| Unlinkd pipe opened on FD 13
2012/03/30 01:32:22| Local cache digest enabled; rebuild/rewrite every 
3600/3600 sec
2012/03/30 01:32:22| Store logging disabled
2012/03/30 01:32:22| Swap maxSize 0 + 262144 KB, estimated 20164 objects
2012/03/30 01:32:22| Target number of buckets: 1008
2012/03/30 01:32:22| Using 8192 Store buckets
2012/03/30 01:32:22| Max Mem  size: 262144 KB
2012/03/30 01:32:22| Max Swap size: 0 KB
2012/03/30 01:32:22| Using Least Load store dir selection
2012/03/30 01:32:22| Set Current Directory to /var/spool/squid3
2012/03/30 01:32:22| Loaded Icons.
2012/03/30 01:32:22| Accepting  accelerated HTTP connections at 
127.0.0.1:280, FD 14.
2012/03/30 01:32:22| Accepting  HTTP connections at [::]:3128, FD 15.
2012/03/30 01:32:22| HTCP Disabled.
2012/03/30 01:32:22| Configuring Parent 127.0.0.1/8080/0
2012/03/30 01:32:22| Squid plugin modules loaded: 0
2012/03/30 01:32:22| Adaptation support is off.
2012/03/30 01:32:22| Ready to serve requests.
2012/03/30 01:32:23| storeLateRelease: released 0 objects



and the access.log while issue some request:

1. GET without any other header

1333064055.374    454 127.0.0.1 TCP_MISS/200 1519 GET 
http://localhost/alfresco/service/catalog/products - 
FIRST_UP_PARENT/myAccel application/json

2. GET without any other header (again)

1333064061.343    645 127.0.0.1 TCP_REFRESH_UNMODIFIED/200 1517 GET 
http://localhost/alfresco/service/catalog/products - 
FIRST_UP_PARENT/myAccel application/json

3. GET with If-Modified-Since header
1333064068.956    397 127.0.0.1 TCP_REFRESH_UNMODIFIED/304 369 GET 
http://localhost/alfresco/service/catalog/products - 
FIRST_UP_PARENT/myAccel application/json


please help me, I think I did what's in 
http://wiki.squid-cache.org/SquidFaq/ReverseProxy but this is not 
working and I lost too much time on the issue already trying to read and 
experimenting on my own.



If I manage to make it work the next step is to make the cache work only 
on /alfresco/service path on the service, any path including query 
string ?key=value...
but for now I would be happy to solve this particular issue.



I also enabled full logging on squid3 to understand what's happening, 
this is the log for the second request above (without any header):
http://pastebin.com/GhazwHCr

(too big to include in this email)

if you need any other information I would gladly provide it.


Thank you very much,
Regards,

Daniele Segato