Log attached. On Thu, 23 Oct 2008 13:45:22 +0200 Henrik Nordstrom <[EMAIL PROTECTED]> wrote:
> taking out squid-users from the loop. > > Nothing odd there. > > Can you redo this test, this time with the following set in squid.conf: > > debug_option ALL,1 48,9 > > then send the cache.log output. > > > Regards > Henrik > > > > On tor, 2008-10-23 at 13:28 +0200, Malte Schröder wrote: > > On Thu, 23 Oct 2008 23:39:01 +1300 > > Amos Jeffries <[EMAIL PROTECTED]> wrote: > > > > > Malte Schröder wrote: > > > > On Thu, 23 Oct 2008 01:10:58 +0200 > > > > Henrik Nordstrom <[EMAIL PROTECTED]> wrote: > > > > > > > >> On ons, 2008-10-22 at 11:31 +0200, Malte Schröder wrote: > > > >> Not normal. > > > >> > > > >> Squid version? > > > > > > > > 3.0.STABLE10 > > > > > > > >> And how did you measure these? You are not counting TIME_WAIT sockets > > > >> are you? > > > > > > > > by getting cache_object://localhost/filedescriptors and checking > > > > sockets in ESTABLISHED state. > > > > > > > > I attached four files with the output of the filedescriptor page. > > > > "start" is the state directly after the launch of squid, 1 is the state > > > > after loading slashdot.org, 2 after reloading slashdot and 3 after > > > > an additional reload. I increased pconn_timeout to 5 minutes so the > > > > effect becomes more visible. The parent is a squid 2.6.STABLE20. > > > > > > > > > > Okay, this is getting into stuff for squid-dev. cc'd. > > > > > > If you are able build your own squid this patch will at least lead an > > > indication of whats going on with the idle FD. > > > > Patch applied, filedescriptors after some reloads on slashdot attached. > > > > > > > > Amos
2008/10/23 15:40:38| Starting Squid Cache version 3.0.STABLE10 for i486-pc-linux-gnu... 2008/10/23 15:40:38| Process ID 18632 2008/10/23 15:40:38| With 65535 file descriptors available 2008/10/23 15:40:38| DNS Socket created at 0.0.0.0, port 43859, FD 7 2008/10/23 15:40:38| Adding nameserver 127.0.0.1 from /etc/resolv.conf 2008/10/23 15:40:38| Adding domain corp.vattenfall.com from /etc/resolv.conf 2008/10/23 15:40:38| Adding domain corp.vattenfall.de from /etc/resolv.conf 2008/10/23 15:40:38| Adding domain eur.corp.vattenfall.com from /etc/resolv.conf 2008/10/23 15:40:38| Adding domain vattenfall.se from /etc/resolv.conf 2008/10/23 15:40:38| Adding domain vattenfall.pl from /etc/resolv.conf 2008/10/23 15:40:38| Unlinkd pipe opened on FD 12 2008/10/23 15:40:38| Local cache digest enabled; rebuild/rewrite every 3600/3600 sec 2008/10/23 15:40:38| Store logging disabled 2008/10/23 15:40:38| Swap maxSize 0 KB, estimated 0 objects 2008/10/23 15:40:38| Target number of buckets: 0 2008/10/23 15:40:38| Using 8192 Store buckets 2008/10/23 15:40:38| Max Mem size: 8192 KB 2008/10/23 15:40:38| Max Swap size: 0 KB 2008/10/23 15:40:38| Using Least Load store dir selection 2008/10/23 15:40:38| Set Current Directory to /var/spool/squid3 2008/10/23 15:40:38| Loaded Icons. 2008/10/23 15:40:38| Accepting HTTP connections at 127.0.0.4, port 7383, FD 10. 2008/10/23 15:40:38| Accepting HTTP connections at 0.0.0.0, port 7080, FD 11. 2008/10/23 15:40:38| Accepting HTTP connections at 0.0.0.0, port 7081, FD 13. 2008/10/23 15:40:38| HTCP Disabled. 2008/10/23 15:40:38| Accepting SNMP messages on port 3402, FD 14. 2008/10/23 15:40:38| Configuring Parent 127.0.0.1/8086/0 2008/10/23 15:40:38| Ready to serve requests. 2008/10/23 15:40:38| Finished rebuilding storage from disk. 2008/10/23 15:40:38| 0 Entries scanned 2008/10/23 15:40:38| 0 Invalid entries. 2008/10/23 15:40:38| 0 With invalid flags. 2008/10/23 15:40:38| 0 Objects loaded. 2008/10/23 15:40:38| 0 Objects expired. 2008/10/23 15:40:38| 0 Objects cancelled. 2008/10/23 15:40:38| 0 Duplicate URLs purged. 2008/10/23 15:40:38| 0 Swapfile clashes avoided. 2008/10/23 15:40:38| Took 0.02 seconds ( 0.00 objects/sec). 2008/10/23 15:40:38| Beginning Validation Procedure 2008/10/23 15:40:38| Completed Validation Procedure 2008/10/23 15:40:38| Validated 25 Entries 2008/10/23 15:40:38| store_swap_size = 0 2008/10/23 15:40:39| storeLateRelease: released 0 objects 2008/10/23 15:40:51.782| pconnNew: adding test_parent:8086 2008/10/23 15:40:51.783| PconnPool::push: pushed FD 16 for test_parent:8086 2008/10/23 15:41:00.831| PconnPool::push: pushed FD 21 for test_parent:8086 2008/10/23 15:41:00.833| PconnPool::push: pushed FD 19 for test_parent:8086 2008/10/23 15:41:00.835| PconnPool::push: pushed FD 25 for test_parent:8086 2008/10/23 15:41:00.837| PconnPool::push: pushed FD 23 for test_parent:8086 2008/10/23 15:41:00.840| PconnPool::push: pushed FD 27 for test_parent:8086 2008/10/23 15:41:01.225| PconnPool::push: pushed FD 15 for test_parent:8086 2008/10/23 15:41:01.229| PconnPool::push: pushed FD 17 for test_parent:8086 2008/10/23 15:41:01.230| IdleConnList::push: growing FD array 2008/10/23 15:41:01.230| PconnPool::push: pushed FD 28 for test_parent:8086 2008/10/23 15:41:01.234| PconnPool::push: pushed FD 29 for test_parent:8086 2008/10/23 15:41:01.237| PconnPool::push: pushed FD 30 for test_parent:8086 2008/10/23 15:41:01.241| PconnPool::push: pushed FD 32 for test_parent:8086 2008/10/23 15:41:01.248| PconnPool::push: pushed FD 34 for test_parent:8086 2008/10/23 15:41:01.250| PconnPool::push: pushed FD 36 for test_parent:8086 2008/10/23 15:41:01.481| PconnPool::push: pushed FD 37 for test_parent:8086 2008/10/23 15:41:01.482| PconnPool::push: pushed FD 38 for test_parent:8086 2008/10/23 15:41:01.482| IdleConnList::push: growing FD array 2008/10/23 15:41:01.482| PconnPool::push: pushed FD 39 for test_parent:8086 2008/10/23 15:41:01.488| PconnPool::push: pushed FD 41 for test_parent:8086 2008/10/23 15:41:01.492| PconnPool::push: pushed FD 42 for test_parent:8086 2008/10/23 15:41:01.499| PconnPool::push: pushed FD 40 for test_parent:8086 2008/10/23 15:41:01.503| PconnPool::push: pushed FD 43 for test_parent:8086 2008/10/23 15:41:01.505| PconnPool::push: pushed FD 44 for test_parent:8086 2008/10/23 15:41:01.737| PconnPool::push: pushed FD 45 for test_parent:8086 2008/10/23 15:41:01.737| PconnPool::push: pushed FD 46 for test_parent:8086 2008/10/23 15:41:01.739| PconnPool::push: pushed FD 48 for test_parent:8086 2008/10/23 15:41:01.744| PconnPool::push: pushed FD 47 for test_parent:8086 2008/10/23 15:41:01.744| PconnPool::push: pushed FD 50 for test_parent:8086 2008/10/23 15:41:01.747| PconnPool::push: pushed FD 49 for test_parent:8086 2008/10/23 15:41:01.760| PconnPool::push: pushed FD 51 for test_parent:8086 2008/10/23 15:41:01.766| PconnPool::push: pushed FD 52 for test_parent:8086 2008/10/23 15:41:01.985| PconnPool::push: pushed FD 53 for test_parent:8086 2008/10/23 15:41:01.989| PconnPool::push: pushed FD 54 for test_parent:8086 2008/10/23 15:41:01.992| IdleConnList::push: growing FD array 2008/10/23 15:41:01.992| PconnPool::push: pushed FD 55 for test_parent:8086 2008/10/23 15:41:01.995| PconnPool::push: pushed FD 57 for test_parent:8086 2008/10/23 15:41:01.996| PconnPool::push: pushed FD 56 for test_parent:8086 2008/10/23 15:41:01.998| PconnPool::push: pushed FD 58 for test_parent:8086 2008/10/23 15:41:02.011| PconnPool::push: pushed FD 59 for test_parent:8086 2008/10/23 15:41:02.017| PconnPool::push: pushed FD 60 for test_parent:8086 2008/10/23 15:41:02.236| PconnPool::push: pushed FD 61 for test_parent:8086 2008/10/23 15:41:02.243| PconnPool::push: pushed FD 62 for test_parent:8086 2008/10/23 15:41:02.243| PconnPool::push: pushed FD 65 for test_parent:8086 2008/10/23 15:41:02.245| PconnPool::push: pushed FD 63 for test_parent:8086 2008/10/23 15:41:02.250| PconnPool::push: pushed FD 64 for test_parent:8086 2008/10/23 15:41:02.251| PconnPool::push: pushed FD 66 for test_parent:8086 2008/10/23 15:41:02.261| PconnPool::push: pushed FD 67 for test_parent:8086 2008/10/23 15:41:02.268| PconnPool::push: pushed FD 68 for test_parent:8086 2008/10/23 15:41:02.527| PconnPool::push: pushed FD 73 for test_parent:8086 2008/10/23 15:41:02.546| PconnPool::push: pushed FD 72 for test_parent:8086 2008/10/23 15:41:02.546| PconnPool::push: pushed FD 69 for test_parent:8086 2008/10/23 15:41:02.546| PconnPool::push: pushed FD 70 for test_parent:8086 2008/10/23 15:41:02.546| PconnPool::push: pushed FD 71 for test_parent:8086 2008/10/23 15:41:10.225| PconnPool::push: pushed FD 75 for test_parent:8086 2008/10/23 15:41:10.230| PconnPool::push: pushed FD 78 for test_parent:8086 2008/10/23 15:41:10.231| PconnPool::push: pushed FD 76 for test_parent:8086 2008/10/23 15:41:10.236| PconnPool::push: pushed FD 79 for test_parent:8086 2008/10/23 15:41:10.237| PconnPool::push: pushed FD 77 for test_parent:8086 2008/10/23 15:41:10.626| PconnPool::push: pushed FD 31 for test_parent:8086 2008/10/23 15:41:10.631| PconnPool::push: pushed FD 74 for test_parent:8086 2008/10/23 15:41:10.635| PconnPool::push: pushed FD 81 for test_parent:8086 2008/10/23 15:41:10.636| PconnPool::push: pushed FD 80 for test_parent:8086 2008/10/23 15:41:10.639| PconnPool::push: pushed FD 83 for test_parent:8086 2008/10/23 15:41:10.646| PconnPool::push: pushed FD 82 for test_parent:8086 2008/10/23 15:41:10.650| PconnPool::push: pushed FD 84 for test_parent:8086 2008/10/23 15:41:10.660| PconnPool::push: pushed FD 86 for test_parent:8086 2008/10/23 15:41:10.880| IdleConnList::push: growing FD array 2008/10/23 15:41:10.880| PconnPool::push: pushed FD 87 for test_parent:8086 2008/10/23 15:41:10.881| PconnPool::push: pushed FD 88 for test_parent:8086 2008/10/23 15:41:10.889| PconnPool::push: pushed FD 90 for test_parent:8086 2008/10/23 15:41:10.892| PconnPool::push: pushed FD 91 for test_parent:8086 2008/10/23 15:41:10.895| PconnPool::push: pushed FD 89 for test_parent:8086 2008/10/23 15:41:10.896| PconnPool::push: pushed FD 93 for test_parent:8086 2008/10/23 15:41:10.900| PconnPool::push: pushed FD 92 for test_parent:8086 2008/10/23 15:41:10.906| PconnPool::push: pushed FD 94 for test_parent:8086 2008/10/23 15:41:11.134| PconnPool::push: pushed FD 95 for test_parent:8086 2008/10/23 15:41:11.137| PconnPool::push: pushed FD 96 for test_parent:8086 2008/10/23 15:41:11.144| PconnPool::push: pushed FD 97 for test_parent:8086 2008/10/23 15:41:11.146| PconnPool::push: pushed FD 98 for test_parent:8086 2008/10/23 15:41:11.150| PconnPool::push: pushed FD 99 for test_parent:8086 2008/10/23 15:41:11.151| PconnPool::push: pushed FD 101 for test_parent:8086 2008/10/23 15:41:11.155| PconnPool::push: pushed FD 100 for test_parent:8086 2008/10/23 15:41:11.159| PconnPool::push: pushed FD 102 for test_parent:8086 2008/10/23 15:41:11.385| PconnPool::push: pushed FD 103 for test_parent:8086 2008/10/23 15:41:11.388| PconnPool::push: pushed FD 104 for test_parent:8086 2008/10/23 15:41:11.391| PconnPool::push: pushed FD 105 for test_parent:8086 2008/10/23 15:41:11.397| PconnPool::push: pushed FD 106 for test_parent:8086 2008/10/23 15:41:11.402| PconnPool::push: pushed FD 107 for test_parent:8086 2008/10/23 15:41:11.403| PconnPool::push: pushed FD 108 for test_parent:8086 2008/10/23 15:41:11.409| PconnPool::push: pushed FD 109 for test_parent:8086 2008/10/23 15:41:11.410| PconnPool::push: pushed FD 110 for test_parent:8086 2008/10/23 15:41:11.637| PconnPool::push: pushed FD 111 for test_parent:8086 2008/10/23 15:41:11.639| PconnPool::push: pushed FD 112 for test_parent:8086 2008/10/23 15:41:11.642| PconnPool::push: pushed FD 113 for test_parent:8086 2008/10/23 15:41:11.654| PconnPool::push: pushed FD 114 for test_parent:8086 2008/10/23 15:41:11.659| PconnPool::push: pushed FD 117 for test_parent:8086 2008/10/23 15:41:11.661| PconnPool::push: pushed FD 118 for test_parent:8086 2008/10/23 15:41:11.664| PconnPool::push: pushed FD 115 for test_parent:8086 2008/10/23 15:41:11.664| PconnPool::push: pushed FD 116 for test_parent:8086 2008/10/23 15:41:11.888| PconnPool::push: pushed FD 121 for test_parent:8086 2008/10/23 15:41:11.889| PconnPool::push: pushed FD 119 for test_parent:8086 2008/10/23 15:41:11.892| PconnPool::push: pushed FD 120 for test_parent:8086 2008/10/23 15:41:11.905| PconnPool::push: pushed FD 122 for test_parent:8086 2008/10/23 15:41:11.915| PconnPool::push: pushed FD 123 for test_parent:8086 2008/10/23 15:41:15.558| PconnPool::push: pushed FD 124 for test_parent:8086
