Median Service time problem again

From: Alain Sabban <Alain.Sabban@dont-contact.us>
Date: Tue, 12 Oct 1999 05:55:22 +0100

Hi,

I've limited the max_open_disk_fds to 50 and set the ipcache_size to 4096.
The problem remains as you can see below.

During these last days, from time to time, i saw the median services times
getting often over 1s and even over 4s.

Any idea ?
Thanks / Alain

                   ---------------------------------------

General runtime info.

Start Time:
           Wed, 06 Oct 1999 06:36:05 GMT
Current Time:
           Fri, 08 Oct 1999 11:35:32 GMT
Connection information for squid:
        Number of clients accessing cache: 3642
        Number of HTTP requests received: 4469933
        Number of ICP messages received: 0
        Number of ICP messages sent: 0
        Number of queued ICP replies: 0
        Request failure ratio: 0.00%
        HTTP requests per minute: 1405.9
        ICP messages per minute: 0.0
        Select loop called: 17180378 times, 11.104 ms avg
Cache information for squid:
        Storage Swap size: 15387926 KB
        Storage Mem size: 116732 KB
        Storage LRU Expiration Age: 0.85 days
        Mean Object Size: 13.82 KB
        Requests given to unlinkd: 878191
Median Service Times (seconds) 5 min 60 min:
        HTTP Requests (All): 4.54239 1.81376
        Cache Misses: 4.79440 2.25116
        Cache Hits: 3.86308 1.11539
        Near Hits: 5.06039 1.91442
        Not-Modified Replies: 3.86308 1.24267
        DNS Lookups: 0.31806 0.27831
        ICP Queries: 0.00000 0.00000
Resource usage for squid:
        UP Time: 190766.560 seconds
        CPU Time: 45855.890 seconds
        CPU Usage: 24.04%
        CPU Usage, 5 minute avg: 27.07%
        CPU Usage, 60 minute avg: 30.78%
        Maximum Resident Size: 0 KB
        Page faults with physical i/o: 913496
Memory usage for squid via mallinfo():
        Total space in arena: 262806 KB
        Ordinary blocks: 259990 KB 3256 blks
        Small blocks: 0 KB 0 blks
        Holding blocks: 2896 KB 4 blks
        Free Small blocks: 0 KB
        Free Ordinary blocks: 2816 KB
        Total in use: 262886 KB 100%
        Total free: 2816 KB 1%
Memory accounted for:
        Total accounted: 225737 KB
File descriptor usage for squid:
        Maximum number of file descriptors: 4096
        Largest file desc currently in use: 1590
        Number of file desc currently in use: 1520
        Available number of file descriptors: 2576
        Reserved number of file descriptors: 100
        Disk files open: 37
Internal Data Structures:
        1116608 StoreEntries
         23519 StoreEntries with MemObjects
         21517 Hot Object Cache Items
        1113794 Filemap bits set
        1113740 on-disk objects

5 Minutes counters

sample_start_time = 939382213.347960 (Fri, 08 Oct 1999 11:30:13 GMT)
sample_end_time = 939382514.135620 (Fri, 08 Oct 1999 11:35:14 GMT)
client_http.requests = 48.582445/sec
client_http.hits = 17.487420/sec
client_http.errors = 0.000000/sec
client_http.kbytes_in = 21.945714/sec
client_http.kbytes_out = 370.493923/sec
client_http.all_median_svc_time = 4.542394 seconds
client_http.miss_median_svc_time = 4.794403 seconds
client_http.nm_median_svc_time = 3.863080 seconds
client_http.nh_median_svc_time = 5.060391 seconds
client_http.hit_median_svc_time = 3.863080 seconds
server.all.requests = 33.066516/sec
server.all.errors = 0.000000/sec
server.all.kbytes_in = 302.532358/sec
server.all.kbytes_out = 17.540613/sec
server.http.requests = 32.767302/sec
server.http.errors = 0.000000/sec
server.http.kbytes_in = 262.816633/sec
server.http.kbytes_out = 17.397655/sec
server.ftp.requests = 0.066492/sec
server.ftp.errors = 0.000000/sec
server.ftp.kbytes_in = 38.186407/sec
server.ftp.kbytes_out = 0.009974/sec
server.other.requests = 0.232722/sec
server.other.errors = 0.000000/sec
server.other.kbytes_in = 1.529318/sec
server.other.kbytes_out = 0.129660/sec
icp.pkts_sent = 0.000000/sec
icp.pkts_recv = 0.000000/sec
icp.queries_sent = 0.000000/sec
icp.replies_sent = 0.000000/sec
icp.queries_recv = 0.000000/sec
icp.replies_recv = 0.000000/sec
icp.replies_queued = 0.000000/sec
icp.query_timeouts = 0.000000/sec
icp.kbytes_sent = 0.000000/sec
icp.kbytes_recv = 0.000000/sec
icp.q_kbytes_sent = 0.000000/sec
icp.r_kbytes_sent = 0.000000/sec
icp.q_kbytes_recv = 0.000000/sec
icp.r_kbytes_recv = 0.000000/sec
icp.query_median_svc_time = 0.000000 seconds
icp.reply_median_svc_time = 0.000000 seconds
dns.median_svc_time = 0.318055 seconds
unlink.requests = 10.738472/sec
page_faults = 10.977844/sec
select_loops = 9.747740/sec
select_fds = 625.860117/sec
average_select_fd_period = 0.001596/fd
median_select_fds = 60.985107
swap_files_cleaned = 0.000000/sec
aborted_requests = 0.272618/sec
syscalls.polls = 18.567916/sec
syscalls.disk.opens = 29.931414/sec
syscalls.disk.closes = 29.931414/sec
syscalls.disk.reads = 29.263169/sec
syscalls.disk.writes = 78.088310/sec
syscalls.disk.seeks = 1.609109/sec
syscalls.disk.unlinks = 0.000000/sec
syscalls.sock.accepts = 42.824230/sec
syscalls.sock.sockets = 20.103883/sec
syscalls.sock.connects = 20.050690/sec
syscalls.sock.binds = 20.040716/sec
syscalls.sock.closes = 55.919847/sec
syscalls.sock.reads = 249.129236/sec
syscalls.sock.writes = 236.336158/sec
syscalls.sock.recvfroms = 0.000000/sec
syscalls.sock.sendtos = 0.000000/sec
cpu_time = 81.430000 seconds
wall_time = 300.787660 seconds
cpu_usage = 27.072254%
Received on Mon Oct 11 1999 - 23:32:30 MDT

This archive was generated by hypermail pre-2.1.9 : Tue Dec 09 2003 - 16:48:47 MST