こんにちは。（株）日立製作所の川崎浩史です。
先日はキャッシュファイルが破損する問題に関して対策版である9.7.8-pre2を
公開頂ましてありがとうございました。
開発環境での確認も完了し、昨日6/2より本番環境での運用を開始しております。
本日メールさせて頂いたのは、不完全なキャッシュファイル作成されるケースが再度
発生しております。
今回は前回対応頂いているケースとは異なり、DeleGateのキャッシュファイルが存在
しない状態でアクセスがありエラーとなった際に発生しているのではないかと思われ
ます。
DeleGateのログを見たのですが今回は、前回のように不完全な状態でWriteしたような
ログは残っておらずどの時点で不完全な状態で作成されたかが分からない状況です。
前回のメールで記載頂いている
|・不完全キャッシュファイルの廃棄
|　受信途中にクライアントから切断され、またDeleGateによる代行受信も行なわれ
|　なかった場合に生じる不完全なキャッシュファイルを、明示的に判定して、削除
|　するようにしました。（この問題も、WinCEでばりばり切断しまくっているうちに
|　見つけました^^;）
に該当するのでしょうか？
添付にて不完全なキャッシュファイルが作成されている該当ファイルへのアクセスに
関するログを送付致しますので上記に該当しているのか確認頂ければ助かります。
また、9.8.2を適用することで不完全なキャッシュファイルが作成された場合（ヘッダ
のContent-Lengthのサイズと実ファイルのサイズが異なる）にマスタ側から取り直され
るのでしょうか？
 
今回エラーとなっているファイルは「C-19-87〜90.xls」でファイルサイズが2,080,256
バイトとなっています。
不完全なキャッシュファイルは286,160バイトで作成日時は6/2の12:49となっています。
 
client135.domain.co.jp - - [02/Jun/2008:10:29:17 +0900] "GET http://server01/dzdoc/商品部/募集資料ライブラリ/C-19-87〜90.xls HTTP/1.0" 200 437755 0*0.032+6.781:P:0H
client135.domain.co.jp - - [02/Jun/2008:10:29:28 +0900] "GET http://server01/dzdoc/商品部/募集資料ライブラリ/C-19-87〜90.xls HTTP/1.0" 206 772105 0*0.141+10.954:RP:0+
client135.domain.co.jp - - [02/Jun/2008:10:29:29 +0900] "GET http://server01/dzdoc/商品部/募集資料ライブラリ/C-19-87〜90.xls HTTP/1.0" 206 4145 0*0.032+0.281:RP:0+
client135.domain.co.jp - - [02/Jun/2008:10:29:31 +0900] "GET http://server01/dzdoc/商品部/募集資料ライブラリ/C-19-87〜90.xls HTTP/1.0" 500 0 0*0.000+0.000:P:0+
client135.domain.co.jp - - [02/Jun/2008:10:29:54 +0900] "GET http://server01/dzdoc/商品部/募集資料ライブラリ/C-19-87〜90.xls HTTP/1.0" 200 1072855 0*0.031+14.860:P:0H
client135.domain.co.jp - - [02/Jun/2008:10:30:17 +0900] "GET http://server01/dzdoc/商品部/募集資料ライブラリ/C-19-87〜90.xls HTTP/1.0" 206 458752 0*0.046+9.204:RP:0+
client135.domain.co.jp - - [02/Jun/2008:10:30:39 +0900] "GET http://server01/dzdoc/商品部/募集資料ライブラリ/C-19-87〜90.xls HTTP/1.0" 206 550657 0*0.031+8.266:RW:0H
client135.domain.co.jp - - [02/Jun/2008:10:33:03 +0900] "GET http://server01/dzdoc/商品部/募集資料ライブラリ/C-19-87〜90.xls HTTP/1.0" 500 0 0*0.000+0.000:P:0H
client135.domain.co.jp - - [02/Jun/2008:10:33:06 +0900] "LOCK http://server01/dzdoc/%E5%95%86%E5%93%81%E9%83%A8/%E5%8B%9F%E9%9B%86%E8%B3%87%E6%96%99%E3%83%A9%E3%82%A4%E3%83%96%E3%83%A9%E3%83%AA/C-19-87%EF%BD%9E90.xls HTTP/1.0" 403 44 0*0.031+1.078:RW:0M
client135.domain.co.jp - - [02/Jun/2008:10:33:06 +0900] "GET http://server01/dzdoc/商品部/募集資料ライブラリ/C-19-87〜90.xls HTTP/1.0" 500 0 0*0.000+0.000:P:0H
client021.domain.co.jp - - [02/Jun/2008:13:49:20 +0900] "GET http://server01/dzdoc/商品部/募集資料ライブラリ/C-19-87〜90.xls HTTP/1.0" 206 4145 0*0.031+0.266:RP:0+
client021.domain.co.jp - - [02/Jun/2008:13:49:22 +0900] "GET http://server01/dzdoc/商品部/募集資料ライブラリ/C-19-87〜90.xls HTTP/1.0" 200 285915 0*0.031+5.360:P:0H
client021.domain.co.jp - - [02/Jun/2008:13:49:37 +0900] "GET http://server01/dzdoc/商品部/募集資料ライブラリ/C-19-87〜90.xls HTTP/1.0" 206 913725 0*0.031+13.735:RP:0+
client021.domain.co.jp - - [02/Jun/2008:13:49:43 +0900] "GET http://server01/dzdoc/商品部/募集資料ライブラリ/C-19-87〜90.xls HTTP/1.0" 206 356005 0*0.063+5.593:RP:0+
client021.domain.co.jp - - [02/Jun/2008:13:49:49 +0900] "GET http://server01/dzdoc/商品部/募集資料ライブラリ/C-19-87〜90.xls HTTP/1.0" 206 269866 0*0.047+5.469:RP:0+
client021.domain.co.jp - - [02/Jun/2008:13:50:09 +0900] "GET http://server01/dzdoc/商品部/募集資料ライブラリ/C-19-87〜90.xls HTTP/1.0" 206 365941 0*0.031+8.078:RW:0H
client021.domain.co.jp - - [02/Jun/2008:13:51:46 +0900] "GET http://server01/dzdoc/商品部/募集資料ライブラリ/C-19-87〜90.xls HTTP/1.0" 200 285915 0*0.032+0.515:S:0H
client021.domain.co.jp - - [02/Jun/2008:13:51:48 +0900] "LOCK http://server01/dzdoc/%E5%95%86%E5%93%81%E9%83%A8/%E5%8B%9F%E9%9B%86%E8%B3%87%E6%96%99%E3%83%A9%E3%82%A4%E3%83%96%E3%83%A9%E3%83%AA/C-19-87%EF%BD%9E90.xls HTTP/1.0" 403 44 0*0.031+1.032:RW:0M
client021.domain.co.jp - - [02/Jun/2008:13:51:48 +0900] "GET http://server01/dzdoc/商品部/募集資料ライブラリ/C-19-87〜90.xls HTTP/1.0" 304 0 0*0.031+0.047:N:0H
client021.domain.co.jp - - [02/Jun/2008:13:52:28 +0900] "GET http://server01/dzdoc/商品部/募集資料ライブラリ/C-19-87〜90.xls HTTP/1.0" 304 0 0*0.032+0.046:N:0H
client021.domain.co.jp - - [02/Jun/2008:13:52:52 +0900] "GET http://server01/dzdoc/商品部/募集資料ライブラリ/C-19-87〜90.xls HTTP/1.0" 304 0 0*0.063+0.047:N:0H
client022.domain.co.jp - - [02/Jun/2008:14:05:53 +0900] "GET http://server01/dzdoc/商品部/募集資料ライブラリ/C-19-87〜90.xls HTTP/1.0" 200 285915 0*0.031+0.500:S:0H
client021.domain.co.jp - - [02/Jun/2008:14:16:04 +0900] "GET http://server01/dzdoc/商品部/募集資料ライブラリ/C-19-87〜90.xls HTTP/1.0" 304 0 0*0.032+0.047:N:0H

上記の通り、10:30頃に初回のアクセスがあり、エラーとなっています。この時点ではキャッシュファイルは出来ていないと思われます。
次のアクセスが13:49頃にアクセスがあり、この際もエラーになっていますがこの時のログが
 
06/02 13:49:16.58 [4332] 1392+16: (3) accepted [28] -@[xx.xx.xx.xx]client021.domain.co.jp:1767 (0.000s)(1)
06/02 13:49:16.58 [4332] 1392+16: # SSL record head[47 45 54 20 68] SSL2 8?/1864
06/02 13:49:16.58 [4332] 1392+16: # SSL record head[47 45 54 20 68] SSL2 8?/1864
06/02 13:49:16.58 [4332] 1392+16: Suspicious HTTP header [client021.domain.co.jp][CTL=0,BIN=27,LEN=71] Referer: http://server01/dzdoc/i/WCu/\.htm^M
06/02 13:49:16.58 [4332] 1392+16: Proxy: host=client021.domain.co.jp; User-Agent: Mozilla/4.0 (compatible; MSIE 6.0; Windows NT 5.1; SV1; .NET CLR 2.0.50727); DIRECT
06/02 13:49:16.58 [4332] 1392+16: HCKA:[0] Keep-Alive; host=client021.domain.co.jp; (User-Agent: Mozilla/4.0 (compatible; MSIE 6.0; Windows NT 5.1; SV1; .NET CLR 2.0.50727))
06/02 13:49:16.60 [4332] 1392+16: REQUEST - GET http://server01/dzdoc/i/WCu/C-19-87`90.xls HTTP/1.0^M
06/02 13:49:16.61 [4332] 1392+16: PATH> http://server01:80!server22.domain.co.jp:8443!client021.domain.co.jp:1767!anonymous@client021.domain.co.jp;1212378556
06/02 13:49:16.61 [4332] 1392+16: REQUEST = [http://server01:80/] GET /dzdoc/i/WCu/C-19-87`90.xls HTTP/1.0^M
06/02 13:49:16.61 [4332] 1392+16: url_escunify: dzdoc/i/WCu/C-19-87`90.xls -> dzdoc/%FFFFFF8F%FFFFFFA4%FFFFFF95i%FFFFFF95%FFFFFF94/%FFFFFF95%FFFFFFE5%FFFFFF8FW%FFFFFF8E%FFFFFF91%FFFFFF97%FFFFFFBF%FFFFFF83%FFFFFF89%FFFFFF83C%FFFFFF83u%FFFFFF83%FFFFFF89%FFFFFF83%FFFFFF8A/C-19-87%FFFFFF81`90.xls
06/02 13:49:16.61 [4332] 1392+16: [0.00,-1][HTTP cache-NONE] F:\CACHE/http/server01/dzdoc/%FFFFFF8F%FFFFFFA4%FFFFFF95i%FFFFFF95%FFFFFF94/%FFFFFF95%FFFFFFE5%FFFFFF8FW%FFFFFF8E%FFFFFF91%FFFFFF97%FFFFFFBF%FFFFFF83%FFFFFF89%FFFFFF83C%FFFFFF83u%FFFFFF83%FFFFFF89%FFFFFF83%FFFFFF8A/C-19-87%FFFFFF81`90.xls
06/02 13:49:16.61 [4332] 1392+16: [0.00,-1][HTTP cache-NONE] F:\CACHE/http/server01/dzdoc/%FFFFFF8F%FFFFFFA4%FFFFFF95i%FFFFFF95%FFFFFF94/%FFFFFF95%FFFFFFE5%FFFFFF8FW%FFFFFF8E%FFFFFF91%FFFFFF97%FFFFFFBF%FFFFFF83%FFFFFF89%FFFFFF83C%FFFFFF83u%FFFFFF83%FFFFFF89%FFFFFF83%FFFFFF8A/C-19-87%FFFFFF81`90.xls
06/02 13:49:16.61 [4332] 1392+16: connectTO: assume in non-blocking mode
06/02 13:49:16.65 [4332] 1392+16: ConnectToServer connected [29] {xx.xx.xx.xx:80 <- xx.xx.xx.xx:1984} [0.031s]
06/02 13:49:16.65 [4332] 1392+16: willSTLS_SV: ServerFlags=48010
06/02 13:49:16.65 [4332] 1392+16: HTTP => (server01:80) GET /dzdoc/i/WCu/C-19-87`90.xls HTTP/1.0^M
06/02 13:49:16.65 [4332] 1392+16: #HT11 FORCE HTTP/1.1 or Connection:keep-alive
06/02 13:49:16.69 [4332] 1392+16: #HT11 SERVER ver[HTTP/1.1] conn[]
06/02 13:49:16.69 [4332] 1392+16: #HT11 server KEEP-ALIVE
06/02 13:49:16.69 [4332] 1392+16: HTTP/1.1 200 Content-{Type:application/vnd.ms-excel Encoding:[/] Leng:2080256} Server:Microsoft-IIS/5.0
06/02 13:49:19.93 [4332] 1392+16: ## got SIGPIPE [1] in HTTP: binaryBody
06/02 13:49:19.93 [4332] 1392+16: ClientEOF: relay_response.SIGPIPE [28 28] 250000 000000 X
06/02 13:49:19.93 [4332] 1392+16: ## (1) SIGPIPE * 1: the recipient seems to be dead, Ctype:application/vnd.ms-excel
06/02 13:49:22.01 [4332] 1392+16: CACHE_TAKEOVER: TIMEOUT=takeover:6
06/02 13:49:22.01 [4332] 1392+16: HTTP transmitted: 245head+285000/000000Fbody=>0txt+285915bin->179000/000000X, 204i/108o/0f/5.3 -----
06/02 13:49:22.01 [4332] 1392+16: rcode=-10002 unlink F:\CACHE/http/server01/dzdoc/%FFFFFF8F%FFFFFFA4%FFFFFF95i%FFFFFF95%FFFFFF94/%FFFFFF95%FFFFFFE5%FFFFFF8FW%FFFFFF8E%FFFFFF91%FFFFFF97%FFFFFFBF%FFFFFF83%FFFFFF89%FFFFFF83C%FFFFFF83u%FFFFFF83%FFFFFF89%FFFFFF83%FFFFFF8A/C-19-87%FFFFFF81`90.xls#LOADING (233472)
06/02 13:49:22.01 [4332] 1392+16: #HT11 close svsokcs[30,31]
06/02 13:49:22.04 [4332] 1392+16: HCKA:[0] closed -- H:HTTPCONF=bugs:no-keepalive
06/02 13:49:22.04 [4332] 1392+16: disconnected [28] -@[xx.xx.xx.xx]client021.domain.co.jp:1767 (5.454s)(1)

「HTTP transmitted: 245head+285000/000000Fbody」の記録が残っており、このサイズが
不完全なキャッシュファイルのサイズと一致しており、このときに不完全なキャッシュ
ファイルが作成されたのではないかと思われます。
 
よろしくお願い致します。