Re: [squid-users] squid 3.2.1 proxying but not caching requests made from an origin server when used as an accelerator

From: Dan Moore <dan.moore_at_8z.com>
Date: Fri, 5 Oct 2012 13:15:50 -0600

Thanks for taking a look Amos.

Is there any area I can increase debugging that might shed a clue as
to why this is happening?

I will request that the vendor remove the 'Pragma:' header and see if
that changes the issue at all.

Thanks,
Dan

On Fri, Oct 5, 2012 at 6:01 AM, Amos Jeffries <squid3_at_treenet.co.nz> wrote:
> 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_at_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_at_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_at_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_at_-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
>>
>> ------------------------------------
>
>

-- 
Dan Moore
Product Development and Technology Team Manager
8z Real Estate - Real Estate for Real Life
8z.com / COhomefinder.com
303 563 4114
dan.moore_at_8z.com
Received on Fri Oct 05 2012 - 19:15:56 MDT

This archive was generated by hypermail 2.2.0 : Mon Oct 08 2012 - 12:00:02 MDT