On http://www.esi.org/architecture_spec_1-0.html I read that ESI processors should disregard the Cache-Control headers and rely on Surrogate-Control instead (does that stand true for included resources as well?).
Yes.
So what happens if an included resource is not under ESI control and has not an ESI header? Will it be cached regularly or will it be fetched every time?
I did a quick setup with a stock Apache configured as follows:
[...]
Hmm. Several things there. I've tested ESI at 500+ request per second rates, for similar test pages - and they are all hits. 450ms sounds like a serious problem. Probably most of that is waiting for your source pages, if they aren't being cached.
Try these one-at-a-time: Have you set a surrogate-id in squid.conf ?
Yep (hopefully ;-)):
httpd_accel_surrogate_id test-id
Try setting the max-age a little higher - say 120. If that 'fixes' the problem, it's a regression and I know where it will be.
No luck. :-/
Up your debug level to All,1 90,2. That will spit out any SC parsing errors.
Nothing helpful there (which should be a good sign IIUC).
Following are some (hopefully helpful) debug informations:
(repeated) manual telnet, always the same output:
Connected to localhost. Escape character is '^]'. GET /test.html HTTP/1.0
HTTP/1.0 200 OK Date: Fri, 22 Aug 2003 21:40:08 GMT Server: Apache/2.0.44 (Unix) DAV/2 Catacomb/0.8.1-dev Cache-Control: max-age=60 Expires: Fri, 22 Aug 2003 21:41:08 GMT Last-Modified: Fri, 22 Aug 2003 12:53:45 GMT Surrogate-Control: max-age=120,content="ESI/1.0" Content-Type: text/html; charset=ISO-8859-1 X-Cache: MISS from linux.local Via: 1.0 linux.local (squid/3.0-PRE3-20030822) Connection: close
[ correct page follows ...]
$ /web/apache/bin/ab -n 100 -c 10 http://localhost:9999/test.html
Benchmarking localhost (be patient).....done [...]
Connnection Times (ms)
min mean[+/-sd] median max
Connect: 0 2 5.7 0 26
Processing: 27 1171 765.9 1409 2061
Waiting: 9 1170 766.4 1409 2061
Total: 27 1172 763.5 1409 2061[...]
Before the test:
$ wc -l /web/apache2/logs/access_log 11404 access_log
After the test:
11616 access_log
(200+ requests being served, all GET with 200 status code, no 304)
This is my current configuration:
$ grep -v ^# /usr/local/squid3/etc/squid.conf | grep -v ^$
http_port 9999 accel defaultsite=localhost:81
icp_port 3130
cache_peer 127.0.0.1 parent 81 0 no-query originserver name=localhost
acl origin dstdomain localhost
cache_peer_access localhost allow origin
http_access allow origin
hierarchy_stoplist cgi-bin ?
acl QUERY urlpath_regex cgi-bin \?
no_cache deny QUERY
logformat squid %ts.%03tu %6tr %>a %Ss/%03Hs %<st %rm %ru %un %Sh/%<A %mt
logformat squidmime %ts.%03tu %6tr %>a %Ss/%03Hs %<st %rm %ru %un %Sh/%<A %mt [%>h] [%<h]
logformat common %>a %ui %un [%tl] "%rm %ru HTTP/%rv" %Hs %<st %Ss:%Sh
logformat combined %>a %ui %un [%tl] "%rm %ru HTTP/%rv" %Hs %<st "%{Referer}>h" "%{User-Agent}>h" %Ss:%Sh
access_log /usr/local/squid3/var/logs/access.log squid
debug_options ALL,1 90,2
auth_param basic children 5
auth_param basic realm Squid proxy-caching web server
auth_param basic credentialsttl 2 hours
refresh_pattern ^ftp: 1440 20% 10080
refresh_pattern ^gopher: 1440 0% 1440
refresh_pattern . 0 20% 4320
acl all src 0.0.0.0/0.0.0.0
acl manager proto cache_object
acl localhost src 127.0.0.1/255.255.255.255
acl to_localhost dst 127.0.0.0/8
acl SSL_ports port 443 563
acl Safe_ports port 80 # http
acl Safe_ports port 21 # ftp
acl Safe_ports port 443 563 # https, snews
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
acl our_networks src 127.0.0.0/8 10.42.42.0/24
http_access allow our_networks
http_access deny all
http_reply_access allow all
icp_access allow all
httpd_accel_surrogate_id test-id
coredump_dir /usr/local/squid3/var/cache
This is an excerpt from store.log. Are those SWAPOUT worrisome?
1061588391.138 SWAPOUT 00 00000000 AD1B9DEB9F880528C885BF3BBE070C78 200 1061588390 1061556825 1061588390 text/html 406/406 GET http://localhost:81/test.html
1061588391.872 SWAPOUT 00 00000001 4C779CE4CE038975791312DD6892B930 200 1061588391 1061541046 1061588391 text/html 1788/1788 GET http://localhost:81/include.html
1061588408.110 RELEASE 00 00000000 AD1B9DEB9F880528C885BF3BBE070C78 200 1061588390 1061556825 1061588390 text/html 406/406 GET http://localhost:81/test.html
1061588408.110 SWAPOUT 00 00000002 AD1B9DEB9F880528C885BF3BBE070C78 200 1061588408 1061556825 1061588408 text/html 406/406 GET http://localhost:81/test.html
1061588409.023 RELEASE 00 00000001 4C779CE4CE038975791312DD6892B930 200 1061588391 1061541046 1061588391 text/html 1788/1788 GET http://localhost:81/include.html
1061588409.023 SWAPOUT 00 00000003 4C779CE4CE038975791312DD6892B930 200 1061588409 1061541046 1061588409 text/html 1788/1788 GET http://localhost:81/include.html
All lines in Squid access are like the following ones:
1061586945.207 1020 255.255.255.255 TCP_CLIENT_REFRESH_MISS/200 0 GET http://localhost:81/include.html - FIRST_UP_PARENT/127.0.0.1 text/html
1061586945.213 2033 127.0.0.1 TCP_CLIENT_REFRESH_MISS/000 2426 GET http://localhost:81/test.html - FIRST_UP_PARENT/127.0.0.1 -
Sorry for the lengthy information, I hope that they might be useful for you to track down what's happening (and I sure hope I did something very silly).
Thanks for your support,
-- Gianugo Rabellino Pro-netics s.r.l. - http://www.pro-netics.com Orixo, the XML business alliance - http://www.orixo.com (Now blogging at: http://blogs.cocoondev.org/gianugo/)
