Re: [squid-users] Is ESI cached?

Robert Collins wrote:
>>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/)