Re: Squid, events, and file descriptors

From: Adrian Chadd <adrian_at_creative.net.au>
Date: Tue, 24 Jun 2008 22:50:19 +0800

On Tue, Jun 24, 2008, Bradley Kite wrote:

> I have some debug for you now:

Argh, just before my exams! God damned users you.

> This server just started showing the symptoms described earlier. When
> dropped into debug mode, the defer count is mostly around 6 or 7
> thousand - each being 1 second then its relative to the time of the
> probem (or the time of the initial request since the problem).
>
> 2008/06/24 15:20:48| clientReadRequest: FD 1944 closed? Defer Count: 5974
> 2008/06/24 15:20:48| clientReadRequest: FD 1942 closed? Defer Count: 6302
> 2008/06/24 15:20:48| clientReadRequest: FD 1941 closed? Defer Count: 6179
> 2008/06/24 15:20:48| clientReadRequest: FD 1940 closed? Defer Count: 7005

Right. It shouldn't be that big. The reason its lasting that long is
because the writes-side hasn't closed and it hasn't hit some kind of
timeout.

Hm, the trouble is that the description is set to "half-closed", but there's
no real indication (there) why its stuck. These are client FDs, so they're
connections -from- clients.

The question is - why is Squid not timing the client-facing filedescriptors
out? Is there some pending reply which isn't being written back correctly?

Henrik?

Adrian

> On this particular occasion the problem has been caught early, so not
> that many FD's are in this state.
>
> squidclient mgr:info is below, if that provides any additional clues:
>
> Squid Object Cache: Version 2.6.STABLE18
> Start Time: Tue, 24 Jun 2008 03:02:55 GMT
> Current Time: Tue, 24 Jun 2008 14:30:21 GMT
> Connection information for squid:
> Number of clients accessing cache: 5081
> Number of HTTP requests received: 5475693
> Number of ICP messages received: 0
> Number of ICP messages sent: 0
> Number of queued ICP replies: 0
> Request failure ratio: 0.00
> Average HTTP requests per minute since start: 7965.5
> Average ICP messages per minute since start: 0.0
> Select loop called: 81904070 times, 0.504 ms avg
> Cache information for squid:
> Request Hit Ratios: 5min: 0.0%, 60min: 0.0%
> Byte Hit Ratios: 5min: 0.7%, 60min: 3.1%
> Request Memory Hit Ratios: 5min: 0.0%, 60min: 0.0%
> Request Disk Hit Ratios: 5min: 0.0%, 60min: 0.0%
> Storage Swap size: 191721208 KB
> Storage Mem size: 916892 KB
> Mean Object Size: 23.52 KB
> Requests given to unlinkd: 0
> Median Service Times (seconds) 5 min 60 min:
> HTTP Requests (All): 0.06286 0.06640
> Cache Misses: 0.06286 0.06640
> Cache Hits: 0.00000 0.00000
> Near Hits: 0.00000 0.00000
> Not-Modified Replies: 0.00000 0.00000
> DNS Lookups: 0.00094 0.00190
> ICP Queries: 0.00000 0.00000
> Resource usage for squid:
> UP Time: 41245.752 seconds
> CPU Time: 5015.237 seconds
> CPU Usage: 12.16%
> CPU Usage, 5 minute avg: 1.06%
> CPU Usage, 60 minute avg: 1.32%
> Process Data Segment Size via sbrk(): 2095744 KB
> Maximum Resident Size: 0 KB
> Page faults with physical i/o: 378705
> Memory usage for squid via mallinfo():
> Total space in arena: 2095876 KB
> Ordinary blocks: 2066961 KB 329163 blks
> Small blocks: 0 KB 0 blks
> Holding blocks: 60984 KB 6 blks
> Free Small blocks: 0 KB
> Free Ordinary blocks: 28914 KB
> Total in use: -2066359 KB 101%
> Total free: 28914 KB 0%
> Total size: -2037444 KB
> Memory accounted for:
> Total accounted: 1677823 KB
> memPoolAlloc calls: 768370423
> memPoolFree calls: 747816806
> File descriptor usage for squid:
> Maximum number of file descriptors: 16384
> Largest file desc currently in use: 2499
> Number of file desc currently in use: 1418
> Files queued for open: 0
> Available number of file descriptors: 14966
> Reserved number of file descriptors: 100
> Store Disk files open: 0
> IO loop method: epoll
> Internal Data Structures:
> 8182835 StoreEntries
> 181239 StoreEntries with MemObjects
> 181238 Hot Object Cache Items
> 8151855 on-disk objects
>
> In particular, squid thinks it has 1418 file descriptors in use.
> netstat shows only a few hundred:
>
> [root_at_elc-url-sqd-13 squid]# netstat -an | grep 3128 | wc -l
> 287
>
> I am now going to set "half_closed_connections off" and see what debug
> can be obtained from that.
>
> In the mean time if you have any other suggestions please let me know.
>
> --
> Brad.

-- 
- Xenion - http://www.xenion.com.au/ - VPS Hosting - Commercial Squid Support -
- $25/pm entry-level VPSes w/ capped bandwidth charges available in WA -
Received on Tue Jun 24 2008 - 14:50:24 MDT

This archive was generated by hypermail 2.2.0 : Wed Jun 25 2008 - 12:00:08 MDT