> On Thu, 2009-04-02 at 11:35 +1200, Amos Jeffries wrote: >> >> IIRC, non-cachable objects larger than max_object_size_in_memory get a >> disk object saved for the transition buffer then released when completed >> whether they need it or not. One of the inefficiencies we are working >> towards killing. > > OK. But that doesn't explain these ones does it? > > 1239123733.599 RELEASE 00 00002503 C11C22024C6BFA7AB028CE37E26CADBD 200 > 1239123131 1234617780 -1 image/gif 1366/1366 GET > http://www.example.org/forum/images/styles/soness/style/footer_top.gif > 1239123733.600 SWAPOUT 00 00002548 C11C22024C6BFA7AB028CE37E26CADBD 200 > 1239123736 1234617780 -1 image/gif 1366/1366 GET > http://www.example.org/forum/images/styles/soness/style/footer_top.gif > 1239124338.647 RELEASE 00 00002548 C11C22024C6BFA7AB028CE37E26CADBD 200 > 1239123736 1234617780 -1 image/gif 1366/1366 GET > http://www.example.org/forum/images/styles/soness/style/footer_top.gif > 1239124338.649 SWAPOUT 00 000025D5 C11C22024C6BFA7AB028CE37E26CADBD 200 > 1239124341 1234617780 -1 image/gif 1366/1366 GET > http://www.example.org/forum/images/styles/soness/style/footer_top.gif > 1239124944.128 RELEASE 00 000025D5 C11C22024C6BFA7AB028CE37E26CADBD 200 > 1239124341 1234617780 -1 image/gif 1366/1366 GET > http://www.example.org/forum/images/styles/soness/style/footer_top.gif > 1239124944.130 SWAPOUT 00 0000261E C11C22024C6BFA7AB028CE37E26CADBD 200 > 1239124946 1234617780 -1 image/gif 1366/1366 GET > http://www.example.org/forum/images/styles/soness/style/footer_top.gif > 1239125550.777 RELEASE 00 0000261E C11C22024C6BFA7AB028CE37E26CADBD 200 > 1239124946 1234617780 -1 image/gif 1366/1366 GET > http://www.example.org/forum/images/styles/soness/style/footer_top.gif > 1239125550.777 SWAPOUT 00 00002660 C11C22024C6BFA7AB028CE37E26CADBD 200 > 1239125553 1234617780 -1 image/gif 1366/1366 GET > http://www.example.org/forum/images/styles/soness/style/footer_top.gif > 1239126156.245 RELEASE 00 00002660 C11C22024C6BFA7AB028CE37E26CADBD 200 > 1239125553 1234617780 -1 image/gif 1366/1366 GET > http://www.example.org/forum/images/styles/soness/style/footer_top.gif > 1239126156.247 SWAPOUT 00 000026D1 C11C22024C6BFA7AB028CE37E26CADBD 200 > 1239126158 1234617780 -1 image/gif 1366/1366 GET > http://www.example.org/forum/images/styles/soness/style/footer_top.gif > 1239126762.193 RELEASE 00 000026D1 C11C22024C6BFA7AB028CE37E26CADBD 200 > 1239126158 1234617780 -1 image/gif 1366/1366 GET > http://www.example.org/forum/images/styles/soness/style/footer_top.gif > 1239126762.193 SWAPOUT 00 0000273B C11C22024C6BFA7AB028CE37E26CADBD 200 > 1239126764 1234617780 -1 image/gif 1366/1366 GET > http://www.example.org/forum/images/styles/soness/style/footer_top.gif > 1239127368.419 RELEASE 00 0000273B C11C22024C6BFA7AB028CE37E26CADBD 200 > 1239126764 1234617780 -1 image/gif 1366/1366 GET > http://www.example.org/forum/images/styles/soness/style/footer_top.gif > 1239127368.419 SWAPOUT 00 000027BF C11C22024C6BFA7AB028CE37E26CADBD 200 > 1239127370 1234617780 -1 image/gif 1366/1366 GET > http://www.example.org/forum/images/styles/soness/style/footer_top.gif > 1239127976.513 RELEASE 00 000027BF C11C22024C6BFA7AB028CE37E26CADBD 200 > 1239127370 1234617780 -1 image/gif 1366/1366 GET > http://www.example.org/forum/images/styles/soness/style/footer_top.gif > 1239127976.515 SWAPOUT 00 00002827 C11C22024C6BFA7AB028CE37E26CADBD 200 > 1239127978 1234617780 -1 image/gif 1366/1366 GET > http://www.example.org/forum/images/styles/soness/style/footer_top.gif > 1239128584.002 RELEASE 00 00002827 C11C22024C6BFA7AB028CE37E26CADBD 200 > 1239127978 1234617780 -1 image/gif 1366/1366 GET > http://www.example.org/forum/images/styles/soness/style/footer_top.gif > 1239128584.002 SWAPOUT 00 00002A59 C11C22024C6BFA7AB028CE37E26CADBD 200 > 1239128586 1234617780 -1 image/gif 1366/1366 GET > http://www.example.org/forum/images/styles/soness/style/footer_top.gif > 1239129189.138 RELEASE 00 00002A59 C11C22024C6BFA7AB028CE37E26CADBD 200 > 1239128586 1234617780 -1 image/gif 1366/1366 GET > http://www.example.org/forum/images/styles/soness/style/footer_top.gif > 1239129189.138 SWAPOUT 00 00002A97 C11C22024C6BFA7AB028CE37E26CADBD 200 > 1239129191 1234617780 -1 image/gif 1366/1366 GET > http://www.example.org/forum/images/styles/soness/style/footer_top.gif > 1239129793.280 RELEASE 00 00002A97 C11C22024C6BFA7AB028CE37E26CADBD 200 > 1239129191 1234617780 -1 image/gif 1366/1366 GET > http://www.example.org/forum/images/styles/soness/style/footer_top.gif > 1239129793.282 SWAPOUT 00 00002AD4 C11C22024C6BFA7AB028CE37E26CADBD 200 > 1239129795 1234617780 -1 image/gif 1366/1366 GET > http://www.example.org/forum/images/styles/soness/style/footer_top.gif > 1239130397.185 RELEASE 00 00002AD4 C11C22024C6BFA7AB028CE37E26CADBD 200 > 1239129795 1234617780 -1 image/gif 1366/1366 GET > http://www.example.org/forum/images/styles/soness/style/footer_top.gif > 1239130397.370 SWAPOUT 00 00003011 C11C22024C6BFA7AB028CE37E26CADBD 200 > 1239130399 1234617780 -1 image/gif 1366/1366 GET > http://www.example.org/forum/images/styles/soness/style/footer_top.gif > > Really, why should that object ever get RELEASEd? > > Here's the header from a fetch of it: > > HTTP/1.0 200 OK > Date: Tue, 07 Apr 2009 18:53:19 GMT > Server: Apache/2 > Last-Modified: Sat, 14 Feb 2009 13:23:00 GMT > ETag: "1b88337-556-462e0da35d500" > Accept-Ranges: bytes > Content-Length: 1366 > Content-Type: image/gif > Age: 197 > X-Cache: HIT from linux > X-Cache-Lookup: HIT from linux:3128 > Via: 1.0 linux (squid/3.0.STABLE10) > Proxy-Connection: keep-alive > > Certainly in this case, it was a cache hit, a memory hit in fact: > > 1239130594.149 2 10.75.22.1 TCP_MEM_HIT/200 1729 GET > http://www.example.org/forum/images/styles/soness/style/footer_top.gif > brian NONE/- image/gif > > Any ideas? 1239130594.149 is a time outside the above trace of SWAPOUT->RELEASE patterns so i can't tell if that request had a matching RELEASE. Could be that earlier copies were requested with must-revalidate or no-cache requests or were testing for If-matches on different ETags. Certainly Age: 197 says the object was generated new at 1239130397.* which matches the time of last RELEASE/SWAPOUT in the trace. I would hazard a guess that those images are in fact being passed through a dynamic script that outputs their binary data and mangles the headers somehow between requests. Check the request + reply set of headers on two or three sequential RELEASE timestamps. Amos