On 5/10/2012 4:31 p.m., Dan Moore wrote:
Hi folks,
I'm running into an issue with a squid setup and wanted to see if
anyone had any ideas about what I'm doing wrong. I am using squid
3.2.1 which I built from source with the default configuration
options.
We are using squid as an accelerator, to cache queries against several
different REST APIs on different servers. The issue is that while the
results are being proxied just fine, they aren't being cached. We
want squid in the middle for performance and access control.
Here's one request in the access log:
67.190.6.171 - - [04/Oct/2012:20:25:15 -0600] "GET
http://qa-api.8z.com/api/v1/neighborhood/11344 HTTP/1.1" 200 1186 "-"
"curl/7.24.0 (i686-pc-cygwin) libcurl/7.24.0 OpenSSL/1.0.1c zlib/1.2.7
libidn/1.22 libssh2/1.4.0" TCP_MISS:FIRSTUP_PARENT
Here's the command I'm using to retrieve the resource: curl
http://qa-api.8z.com/api/v1/neighborhood/11344
No matter how often I retrieve the resource, I still get that
TCP_MISS:FIRSTUP_PARENT in the access log.
Here's the relevant section of the config (at least what I think is
the relevant section, full squid.conf below):
------------------
http_access allow api_sites
http_access deny all
http_port 80 accel vhost
cache_peer 74.86.206.124 parent 80 0 no-query originserver
name=terabitz8z forceddomain=qa-8z.kwetoo.com
acl neighborhood_api urlpath_regex ^/api/v1/neighborhood
cache_peer_access terabitz8z allow neighborhood_api
cache_peer_access terabitz8z deny all
------------------
Below is the cache log for one of the requests, with the debugging set
to 2. I'd love to hear any suggestions on which sections of source
code I should set to higher debugging levels (based on this table:
http://wiki.squid-cache.org/KnowledgeBase/DebugSections ). Nothing
jumps out at me when I read it.
Nothing bad appears to happen when I bounce squid. Tried playing with
the cache_peer line: no-digest and it didn't seem to help. Looked at
http_port options, but nothing seemed to apply.
I confirmed that the squid cache directories are writable by the
nobody user. I have set it up against another host and the 'Vary:
Accept-Encoding' header seemed to cause the issue. However, I can't
see why? It's not like the Vary: header includes user-agent or
anything like that.
By the way, the API is managed by a third party, so I can request that
header fields be removed, but am not guaranteed it will be possible.
When I make the request, I see there is a new file in the cache dir:
/usr/local/squid/var/cache/squid/00/00/00000004 and the contents of
that file are the requested information. And each time I make the
request, that same file gets saved again, but has a new timestamp.
This makes me think that I have something misconfigured?
I can't see anything misconfigured, and the HTTP headers look like they
should be cached for up to 2hrs.
Very strange.
The empty Pragma: header should not be there at all but that should not
affect caching.
Amos
Here's the timestamps of that cache file after I make three separate
curl requests each one minute apart:
------------------
[mooreds@proxy-stage1 ~]$ sudo ls -l
/usr/local/squid/var/cache/squid/00/00/00000004
-rw-r----- 1 nobody nobody 1287 Oct 4 21:14
/usr/local/squid/var/cache/squid/00/00/00000004
[mooreds@proxy-stage1 ~]$ sudo ls -l
/usr/local/squid/var/cache/squid/00/00/00000004
-rw-r----- 1 nobody nobody 1287 Oct 4 21:15
/usr/local/squid/var/cache/squid/00/00/00000004
[mooreds@proxy-stage1 ~]$ sudo ls -l
/usr/local/squid/var/cache/squid/00/00/00000004
-rw-r----- 1 nobody nobody 1287 Oct 4 21:16
/usr/local/squid/var/cache/squid/00/00/00000004
------------------
Any help would be appreciated. Should I review my configuration file?
Ask to have headers removed? Play around with the caching setup
using an origin server control? Resources I should read? I spent
most of the afternoon looking around on the internet, playing with
different settings and servers, and seem to have hit a brick wall.
Thanks so much for any help.
Dan Moore
cache.log
------------------------------------
2012/10/04 20:25:15.118 kid1| TcpAcceptor.cc(188) doAccept: New
connection on FD 16
2012/10/04 20:25:15.118 kid1| TcpAcceptor.cc(263) acceptNext:
connection on local=[::]:80 remote=[::] FD 16 flags=9
2012/10/04 20:25:15.844 kid1| HTTP Client local=65.38.188.183:80
remote=67.190.6.171:61991 FD 12 flags=1
2012/10/04 20:25:15.844 kid1| HTTP Client REQUEST:
---------
GET /api/v1/neighborhood/11344 HTTP/1.1
User-Agent: curl/7.24.0 (i686-pc-cygwin) libcurl/7.24.0 OpenSSL/1.0.1c
zlib/1.2.7 libidn/1.22 libssh2/1.4.0
Host: qa-api.8z.com
Accept: */*
----------
2012/10/04 20:25:15.844 kid1| The request GET
http://qa-api.8z.com/api/v1/neighborhood/11344 is 1, because it
matched 'api_sites'
2012/10/04 20:25:15.844 kid1| client_side_request.cc(734)
clientAccessCheck2: No adapted_http_access configuration. default:
ALLOW
2012/10/04 20:25:15.844 kid1| The request GET
http://qa-api.8z.com/api/v1/neighborhood/11344 is 1, because it
matched 'api_sites'
2012/10/04 20:25:15.844 kid1| forward.cc(103) FwdState: Forwarding
client request local=65.38.188.183:80 remote=67.190.6.171:61991 FD 12
flags=1, url=http://qa-api.8z.com/api/v1/neighborhood/11344
2012/10/04 20:25:15.844 kid1| aclRegexData::match: match
'(^/api/v1/neighborhood)' found in '/api/v1/neighborhood/11344'
2012/10/04 20:25:15.844 kid1| aclRegexData::match: match
'(^/api/v1/neighborhood)' found in '/api/v1/neighborhood/11344'
2012/10/04 20:25:15.844 kid1| Find IP destination for:
http://qa-api.8z.com/api/v1/neighborhood/11344' via 74.86.206.124
2012/10/04 20:25:15.844 kid1| Find IP destination for:
http://qa-api.8z.com/api/v1/neighborhood/11344' via 74.86.206.124
2012/10/04 20:25:15.844 kid1| Found sources for
'http://qa-api.8z.com/api/v1/neighborhood/11344'
2012/10/04 20:25:15.844 kid1| always_direct = 0
2012/10/04 20:25:15.844 kid1| never_direct = 0
2012/10/04 20:25:15.844 kid1| cache_peer = local=0.0.0.0
remote=74.86.206.124:80 flags=1
2012/10/04 20:25:15.844 kid1| cache_peer = local=0.0.0.0
remote=74.86.206.124:80 flags=1
2012/10/04 20:25:15.844 kid1| timedout = 0
2012/10/04 20:25:15.861 kid1| HTTP Server local=65.38.188.183:37032
remote=74.86.206.124:80 FD 14 flags=1
2012/10/04 20:25:15.861 kid1| HTTP Server REQUEST:
---------
GET /api/v1/neighborhood/11344 HTTP/1.1
User-Agent: curl/7.24.0 (i686-pc-cygwin) libcurl/7.24.0 OpenSSL/1.0.1c
zlib/1.2.7 libidn/1.22 libssh2/1.4.0
Host: qa-8z.kwetoo.com
Accept: */*
Via: 1.1 proxy-stage1.chfops.net (squid/3.2.1)
Surrogate-Capability: proxy-stage1.chfops.net="Surrogate/1.0"
X-Forwarded-For: 67.190.6.171
Cache-Control: max-age=259200
Connection: keep-alive
----------
2012/10/04 20:25:15.903 kid1| ctx: enter level 0:
'http://qa-api.8z.com/api/v1/neighborhood/11344'
2012/10/04 20:25:15.903 kid1| HTTP Server local=65.38.188.183:37032
remote=74.86.206.124:80 FD 14 flags=1
2012/10/04 20:25:15.903 kid1| HTTP Server REPLY:
---------
HTTP/1.1 200 OK
Date: Fri, 05 Oct 2012 02:33:28 GMT
Server: Apache/2.2.21 (Unix) DAV/2 mod_ssl/2.2.21 OpenSSL/1.0.0c
PHP/5.3.8 mod_apreq2-20090110/2.7.1 mod_perl/2.0.5 Perl/v5.10.1
X-Powered-By: PHP/5.3.8
Set-Cookie: PHPSESSID=aj7ehqh9rr98uodpq528g3hvs0; path=/
Expires: Fri, 05 Oct 2012 04:33:28 GMT
Cache-Control: max-age=7200
Pragma:
Vary: Accept-Encoding
Content-Length: 638
Keep-Alive: timeout=5, max=100
Connection: Keep-Alive
Content-Type: application/x-javascript
{"error":null,"data":[{"id":11344,"name":"rogers-park","displayName":"Rogers
Park","city":"Fort
Collins","region":"northern-colorado","state":"CO","assignedRealtor":null,"description":"","extraDescription":"","rssFeed":null,"flickrFeed":"fortcollinsrogerspark","pageTitle":"","pageDescription":"","pageKeywords":"","mapPolygon":[[40.58197000000001,-105.11509],[40.58219,-105.1315],[40.58182,-105.13373],[40.57874,-105.13378],[40.57501000000001,-105.13373],[40.57477,-105.11612],[40.57461,-105.11512],[40.58197000000001,-105.11509]],"url":"\/neighborhoods\/CO\/fort-collins\/rogers-park","latitude":"40.578405","longitude":"-105.124428"}]}
----------
2012/10/04 20:25:15.903 kid1| ctx: exit level 0
2012/10/04 20:25:15.903 kid1| The reply for GET
http://qa-api.8z.com/api/v1/neighborhood/11344 is 1, because it
matched 'neighborhood_api'
2012/10/04 20:25:15.904 kid1| HTTP Client local=65.38.188.183:80
remote=67.190.6.171:61991 FD 12 flags=1
2012/10/04 20:25:15.904 kid1| HTTP Client REPLY:
---------
HTTP/1.1 200 OK
Date: Fri, 05 Oct 2012 02:33:28 GMT
Server: Apache/2.2.21 (Unix) DAV/2 mod_ssl/2.2.21 OpenSSL/1.0.0c
PHP/5.3.8 mod_apreq2-20090110/2.7.1 mod_perl/2.0.5 Perl/v5.10.1
X-Powered-By: PHP/5.3.8
Set-Cookie: PHPSESSID=aj7ehqh9rr98uodpq528g3hvs0; path=/
Expires: Fri, 05 Oct 2012 04:33:28 GMT
Cache-Control: max-age=7200
Pragma:
Vary: Accept-Encoding
Content-Length: 638
Content-Type: application/x-javascript
X-Cache: MISS from proxy-stage1.chfops.net
Via: 1.1 proxy-stage1.chfops.net (squid/3.2.1)
Connection: keep-alive
----------
2012/10/04 20:25:15.904 kid1| storeCreate: Selected dir 0 for -1@-1=0/2/0/1
2012/10/04 20:25:16.024 kid1| client_side.cc(764) swanSong:
local=65.38.188.183:80 remote=67.190.6.171:61991 flags=1
------------------------------------
squid.conf
------------------------------------
acl localnet src 10.0.0.0/8 # RFC1918 possible internal network
acl localnet src 172.16.0.0/12 # RFC1918 possible internal network
acl localnet src 192.168.0.0/16 # RFC1918 possible internal network
acl localnet src fc00::/7 # RFC 4193 local private network range
acl localnet src fe80::/10 # RFC 4291 link-local (directly
plugged) machines
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 localhost manager
http_access deny manager
http_access deny !Safe_ports
http_access deny CONNECT !SSL_ports
acl api_sites dstdomain qa-api.8z.com proxy-stage1.chfops.net
http_access allow api_sites
http_access deny all
http_port 80 accel vhost
cache_dir ufs /usr/local/squid/var/cache/squid 100 16 256
coredump_dir /usr/local/squid/var/cache/squid
refresh_pattern ^ftp: 1440 20% 10080
refresh_pattern ^gopher: 1440 0% 1440
refresh_pattern -i (/cgi-bin/|\?) 0 0% 0
refresh_pattern . 20 20% 4320
cache_peer 74.86.206.124 parent 80 0 no-query originserver
name=terabitz8z forceddomain=qa-8z.kwetoo.com
acl neighborhood_api urlpath_regex ^/api/v1/neighborhood
cache_peer_access terabitz8z allow neighborhood_api
cache_peer_access terabitz8z deny all
logformat combined %>a %ui %un [%{%d/%b/%Y:%H:%M:%S %z}tl] "%rm %ru
HTTP/%rv" %>Hs %<st "%{Referer}>h" "%{User-Agent}>h" %Ss:%Sh
access_log /usr/local/squid/var/logs/api_access.log combined api_sites
logfile_rotate 0
cache_effective_user nobody
debug_options ALL,2
------------------------------------
