Hi,

HTTP proxy caching is a bit odd. This is with version 9.3.0.

The HTTP proxy runs with "delegated -P8080 SERVER=http CACHE=do".
Files are cached but they do not get used after the same file is
retrieved. Instead the file is retrieved and then re-cached.

I can force cache to be used with "delegated -P8080 SERVER=http
CACHE=do CONNECT="cache:*:*"". This makes the page load only if
there's a cache and cache retrieval works fine. However, non-cache
pages won't work.

Here are some logs for HTTP with caching, caching only, and the
response header. Logs are for different files on the same host.
Outputs were generally the same except for the file name.

I don't see a lot of difference except with cache only there's a "HTTP
cache-VALID". Any ideas on how to get the cache working or force it to
work?


Cache not working log:
[1328] 5+2/6/6: HCKA:[6] KeepAlive: GET N =>1
[1328] 5+2/6/6: TCP_NODELAY[53] 0 -> 1
[1328] 5+2/6/6: TCP_NODELAY[53] 1 -> 0
[1328] 5+2/6/6: Request Content-Type: application/x-www-form-urlencoded
[1328] 5+2/6/6: IGNORE request: Keep-Alive: 300^M
[1328] 5+2/6/6: HTTP Relay_request_head (133 bytes/6 lines)
[1328] 5+2/6/6: Proxy: host=localhost; User-Agent: MyApp; DIRECT
[1328] 5+2/6/6: HTTP Relay_request done (133 bytes/6 lines)
[1328] 5+2/6/6: Host: xxx.xxx.xxx.xxx:80
[1328] 5+2/6/6: REQUEST - GET xxxxxxxxxx HTTP/1.1^M
[1328] 5+2/6/6: ImMaster? 0 <http://-:80> <http://xxx.xxx.xxx.xxx:80/>
[1328] 5+2/6/6: REMOTE > GET xxxxxxxxxx HTTP/1.1^M
[1328] 5+2/6/6: PATH>
http://xxx.xxx.xxx.xxx:80!localhost:8080!localhost:2348!anonymous@localhost;1163191741
[1328] 5+2/6/6: REQUEST = (no-cache)[http://xxx.xxx.xxx.xxx:80/] GET
xxxxxxxxxx HTTP/1.1^M
[1328] 5+2/6/6: checking delegate-internal: self=0 GET xxxxxxxxxx HTTP/1.1^M
[1328] 5+2/6/6: forwarding by RELAY=vhost [xxx.xxx.xxx.xxx:80]
[1328] 5+2/6/6: PERMITTED: http://xxx.xxx.xxx.xxx
[1328] 5+2/6/6: CACHE hostname: xxx.xxx.xxx.xxx -> xxx.xxx.xxx.xxx
[1328] 5+2/6/6: CACHE: `C:/Program Files/DeleGate/cache/$[server:%P/%L/%p]'
[1328] 5+2/6/6: CACHE: `C:/Program
Files/DeleGate/cache/http/xxx.xxx.xxx.xxxxxxxxxxxxx'
[1328] 5+2/6/6: EXPIRE 3600s = 3600
[1328] 5+2/6/6: dirfopen(C:/Program
Files/DeleGate/cache/http/xxx.xxx.xxx.xxxxxxxxxxxxx#LOADING,r+): 0
[-1]
[1328] 5+2/6/6: dirfopen(C:/Program
Files/DeleGate/cache/http/xxx.xxx.xxx.xxxxxxxxxxxxx#LOADING,w+):
6e47b0 [22]
[1328] 5+2/6/6: HTTP locked for write [22] 0
[1328] 5+2/6/6: expfopen: C:/Program
Files/DeleGate/cache/http/xxx.xxx.xxx.xxxxxxxxxxxxx
[1328] 5+2/6/7: #HT11 getServ  0.16s*7 SERVER REUSE (25/33)
[xxx.xxx.xxx.xxx:80] xxx.xxx.xxx.xxx
[1328] 5+2/6/7: HTTP relayed request 116head
[1328] 5+2/6/7: CacheMtime: 1163191750 : 1163191750
[1328] 5+2/6/7: connDelay: 0.00sec, firstResp: 0.11sec
[1328] 5+2/6/7: URL BASE = 10/45 [Patch/061/x2t%40Qqt%2C%28X1%25%27%20Z%3D1v!05]
[1328] 5+2/6/7: LINGER: [53] 30 4{1,30}
[1328] 5+2/6/7: #HT11 NO-response-buffering: chunked mode
[1328] 5+2/6/7: #HT11 chunked, should skip: Content-Length: 140161^M
[1328] 5+2/6/7: #HT11 SERVER ver[HTTP/1.1] conn[]
[1328] 5+2/6/7: #HT11 server KEEP-ALIVE
[1328] 5+2/6/7: #HT11 --putChunk-Header: Transfer-Encoding: chunked^M
[1328] 5+2/6/7: HTTP/1.1 200 Content-{Type:All Encoding:[/]
Leng:140161} Server:Microsoft-IIS/6.0
[1328] 5+2/6/7: buffered(3851)
[1328] 5+2/6/7: #HT11 --putChunk[1] 3851
[1328] 5+2/6/7: #HT11 --putChunk[2] 16384
[1328] 5+2/6/7: #HT11 --putChunk[3] 10180
[1328] 5+2/6/7: #HT11 --putChunk[4] 16384
[1328] 5+2/6/7: #HT11 --putChunk[5] 14276
[1328] 5+2/6/7: #HT11 --putChunk[6] 16384
[1328] 5+2/6/7: #HT11 --putChunk[7] 16384
[1328] 5+2/6/7: #HT11 --putChunk[8] 2272
[1328] 5+2/6/7: #HT11 --putChunk[9] 13140
[1328] 5+2/6/7: #HT11 --putChunk[10] 16384
[1328] 5+2/6/7: #HT11 --putChunk[11] 1136
[1328] 5+2/6/7: #HT11 --putChunk[12] 13386
[1328] 5+2/6/7: #HT11 --putChunk[13] 0
[1328] 5+2/6/7: HTTP RESPONSE FLUSH: DO (HCKA=1)
[1328] 5+2/6/7: TCP_NODELAY[53] 0 -> 1
[1328] 5+2/6/7: TCP_NODELAY[53] 1 -> 0
[1328] 5+2/6/7: HTTP transmitted:
245head+140000/00000Fbody=>0txt+140161bin->140000/00000X,
45i/13o/0f/0.4
[1328] 5+2/6/7: relay_response()=0, cache=6e47b0, httpStat=N DontTruncate=0
[1328] 5+2/6/7: 140406 bytes written to [C:/Program
Files/DeleGate/cache/http/xxx.xxx.xxx.xxxxxxxxxxxxx#LOADING]
[1328] 5+2/6/7: #HT11 putServ(31/32) xxx.xxx.xxx.xxx:80
[1328] 5+2/6/7: {L} RENAMED [C:/Program
Files/DeleGate/cache/http/xxx.xxx.xxx.xxxxxxxxxxxxx]
[1328] 5+2/6/7: dirfopen(C:/Program Files/DeleGate/act/restart/_8080_,r): 0 [-1]


Cache only log:
[3196] 8+1/15: HCKA:[15] KeepAlive: GET H =>1
[3196] 8+1/15: TCP_NODELAY[5] 0 -> 1
[3196] 8+1/15: TCP_NODELAY[5] 1 -> 0
[3196] 8+1/15: Request Content-Type: application/x-www-form-urlencoded
[3196] 8+1/15: IGNORE request: Keep-Alive: 300^M
[3196] 8+1/15: HTTP Relay_request_head (133 bytes/6 lines)
[3196] 8+1/15: Proxy: host=localhost; User-Agent: MyApp; DIRECT
[3196] 8+1/15: HTTP Relay_request done (133 bytes/6 lines)
[3196] 8+1/15: Host: xxx.xxx.xxx.xxx:80
[3196] 8+1/15: REQUEST - GET xxxxxxxxxx HTTP/1.1^M
[3196] 8+1/15: ImMaster? 0 <http://-:80> <http://xxx.xxx.xxx.xxx:80/>
[3196] 8+1/15: REMOTE > GET xxxxxxxxxx HTTP/1.1^M
[3196] 8+1/15: PATH>
http://xxx.xxx.xxx.xxx:80!localhost:8080!localhost:2430!anonymous@localhost;1163192115
[3196] 8+1/15: REQUEST = (no-cache)[http://xxx.xxx.xxx.xxx:80/] GET
xxxxxxxxxx HTTP/1.1^M
[3196] 8+1/15: checking delegate-internal: self=0 GET xxxxxxxxxx HTTP/1.1^M
[3196] 8+1/15: forwarding by RELAY=vhost [xxx.xxx.xxx.xxx:80]
[3196] 8+1/15: PERMITTED: http://xxx.xxx.xxx.xxx
[3196] 8+1/15: CACHE hostname: xxx.xxx.xxx.xxx -> xxx.xxx.xxx.xxx
[3196] 8+1/15: CACHE: `C:/Program Files/DeleGate/cache/$[server:%P/%L/%p]'
[3196] 8+1/15: CACHE: `C:/Program
Files/DeleGate/cache/http/xxx.xxx.xxx.xxxxxxxxxxxxx'
[3196] 8+1/15: expfopen: C:/Program
Files/DeleGate/cache/http/xxx.xxx.xxx.xxxxxxxxxxxxx
[3196] 8+1/15: [0.01,1484][HTTP cache-VALID: 3956 < 2147483647]
C:/Program Files/DeleGate/cache/http/xxx.xxx.xxx.xxxxxxxxxxxxx
[3196] 8+1/15: URL BASE = 10/60 [xxxxxxxxxx]
[3196] 8+1/15: LINGER: [5] 30 4{1,30}
[3196] 8+1/15: #HT11 SERVER ver[HTTP/1.1] conn[]
[3196] 8+1/15: HTTP/1.1 200 Content-{Type:All Encoding:[/] Leng:1268}
Server:Microsoft-IIS/6.0
[3196] 8+1/15: HTTP RESPONSE FLUSH: DO (HCKA=1)
[3196] 8+1/15: TCP_NODELAY[5] 0 -> 1
[3196] 8+1/15: TCP_NODELAY[5] 1 -> 0
[3196] 8+1/15: HTTP transmitted:
243head+1268/1268body=>0txt+0bin->1268/1268, 10i/2o/0f/0.0
[3196] 8+1/15: HTTP <=-= 200 [C:/Program
Files/DeleGate/cache/http/xxx.xxx.xxx.xxxxxxxxxxxxx] GET xxxxxxxxxx
HTTP/1.1^M
[3196] 8+1/15: dirfopen(C:/Program Files/DeleGate/act/restart/_8080_,r): 0 [-1]


HTTP header:
HTTP/1.1 200 OK
Content-Length: 2134044
Content-Type: All
Last-Modified: Sat, 04 Nov 2006 06:15:36 GMT
Accept-Ranges: bytes
ETag: "0343ba4d8ffc61:1fa"
Server: Microsoft-IIS/6.0
X-Powered-By: ASP.NET

Tetsu