Re: [squid-users] Cache size is decreasing

From: Mr. Issa\(*\) <xnixguy_at_gmail.com>
Date: Sun, 4 Apr 2010 10:44:17 +0300

Cache Utilization:

Cache Utilisation:

Last 5 minutes:
sample_start_time = 1270370128.471469 (Sun, 04 Apr 2010 08:35:28 GMT)
sample_end_time = 1270370428.475867 (Sun, 04 Apr 2010 08:40:28 GMT)
client_http.requests = 74.968901/sec
client_http.hits = 32.009531/sec
client_http.errors = 0.000000/sec
client_http.kbytes_in = 63.332405/sec
client_http.kbytes_out = 1518.634403/sec
client_http.all_median_svc_time = 0.469653 seconds
client_http.miss_median_svc_time = 0.898576 seconds
client_http.nm_median_svc_time = 0.000000 seconds
client_http.nh_median_svc_time = 0.444919 seconds
client_http.hit_median_svc_time = 0.000000 seconds
server.all.requests = 47.595969/sec
server.all.errors = 0.000000/sec
server.all.kbytes_in = 1082.214135/sec
server.all.kbytes_out = 49.639272/sec
server.http.requests = 47.595969/sec
server.http.errors = 0.000000/sec
server.http.kbytes_in = 1082.214135/sec
server.http.kbytes_out = 49.639272/sec
server.ftp.requests = 0.000000/sec
server.ftp.errors = 0.000000/sec
server.ftp.kbytes_in = 0.000000/sec
server.ftp.kbytes_out = 0.000000/sec
server.other.requests = 0.000000/sec
server.other.errors = 0.000000/sec
server.other.kbytes_in = 0.000000/sec
server.other.kbytes_out = 0.000000/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.186387 seconds
unlink.requests = 0.000000/sec
page_faults = 0.000000/sec
select_loops = 1425.702433/sec
select_fds = 1506.081254/sec
average_select_fd_period = 0.000664/fd
median_select_fds = 0.000000
swap.outs = 12.696481/sec
swap.ins = 34.692825/sec
swap.files_cleaned = 8.033216/sec
aborted_requests = 1.393313/sec
syscalls.polls = 1425.702433/sec
syscalls.disk.opens = 33.839504/sec
syscalls.disk.closes = 67.665675/sec
syscalls.disk.reads = 85.932074/sec
syscalls.disk.writes = 147.074511/sec
syscalls.disk.seeks = 0.000000/sec
syscalls.disk.unlinks = 14.563120/sec
syscalls.sock.accepts = 56.059178/sec
syscalls.sock.sockets = 24.222978/sec
syscalls.sock.connects = 24.206312/sec
syscalls.sock.binds = 24.222978/sec
syscalls.sock.closes = 53.089222/sec
syscalls.sock.reads = 679.016712/sec
syscalls.sock.writes = 790.638409/sec
syscalls.sock.recvfroms = 6.759901/sec
syscalls.sock.sendtos = 3.409950/sec
cpu_time = 22.005375 seconds
wall_time = 300.004398 seconds
cpu_usage = 7.335017%

Squid Object Cache: Version 2.7.STABLE9
Connection information for squid:
        Number of clients accessing cache: 0
        Number of HTTP requests received: 19761492
        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: 7439.0
        Average ICP messages per minute since start: 0.0
        Select loop called: 235829976 times, 0.676 ms avg
Cache information for squid:
        Request Hit Ratios: 5min: 41.4%, 60min: 43.1%
        Byte Hit Ratios: 5min: 27.6%, 60min: 24.7%
        Request Memory Hit Ratios: 5min: 33.6%, 60min: 29.2%
        Request Disk Hit Ratios: 5min: 37.9%, 60min: 39.3%
        Storage Swap size: 301573020 KB
        Storage Mem size: 5243024 KB
        Mean Object Size: 23.09 KB
        Requests given to unlinkd: 0
Median Service Times (seconds) 5 min 60 min:
        HTTP Requests (All): 0.46965 0.44492
        Cache Misses: 0.89858 0.85130
        Cache Hits: 0.00000 0.00000
        Near Hits: 0.44492 0.46965
        Not-Modified Replies: 0.00000 0.00000
        DNS Lookups: 0.18639 0.18639
        ICP Queries: 0.00000 0.00000
Resource usage for squid:
        UP Time: 159388.998 seconds
        CPU Time: 14041.662 seconds
        CPU Usage: 8.81%
        CPU Usage, 5 minute avg: 7.24%
        CPU Usage, 60 minute avg: 5.94%
        Process Data Segment Size via sbrk(): 1040036 KB
        Maximum Resident Size: 0 KB
        Page faults with physical i/o: 3
Memory usage for squid via mallinfo():
        Total space in arena: 233180 KB
        Ordinary blocks: 225885 KB 11433 blks
        Small blocks: 0 KB 0 blks
        Holding blocks: 276604 KB 5 blks
        Free Small blocks: 0 KB
        Free Ordinary blocks: 7294 KB
        Total in use: 502489 KB 99%
        Total free: 7294 KB 1%
        Total size: 509784 KB
Memory accounted for:
        Total accounted: 7770073 KB
        memPoolAlloc calls: 2639181306
        memPoolFree calls: 2583577860
File descriptor usage for squid:
        Maximum number of file descriptors: 8192
        Largest file desc currently in use: 3792
        Number of file desc currently in use: 2775
        Files queued for open: 4
        Available number of file descriptors: 5413
        Reserved number of file descriptors: 100
        Store Disk files open: 51
        IO loop method: epoll
Internal Data Structures:
        13107338 StoreEntries
        669218 StoreEntries with MemObjects
        667967 Hot Object Cache Items
        13062902 on-disk objects

I issued this today to check the store_swap_size value @ last time
squid was started ... But why did Squid didnt shutdown properly? the
shutdown_lifetime is already set to 50 seconds isn't that enough?

pr0xySRV:~# less /var/logs/squid/cache.log | grep store_swap_size
2010/03/24 22:50:42| store_swap_size = 38813132k
2010/03/24 22:52:18| store_swap_size = 38813132k
2010/03/26 17:34:50| store_swap_size = 83351932k
2010/03/27 12:24:15| store_swap_size = 103396892k
2010/03/27 12:27:00| store_swap_size = 103396892k
2010/03/29 14:59:49| store_swap_size = 175869696k
2010/03/29 17:47:16| store_swap_size = 158334488k
2010/03/31 02:14:25| store_swap_size = 194989120k
2010/03/31 02:19:02| store_swap_size = 194989120k
2010/03/31 02:25:36| store_swap_size = 194989120k
2010/03/31 02:35:05| store_swap_size = 194989120k
2010/04/01 00:53:27| store_swap_size = 219420056k
2010/04/01 01:14:12| store_swap_size = 219740988k
2010/04/01 15:09:14| store_swap_size = 231067008k
2010/04/02 15:17:55| store_swap_size = 125951712k
2010/04/02 15:25:56| store_swap_size = 251919768k

as you can notice the last 2 values of store_swap_size they are
totally different....

What could be happening?
2010/4/4 Henrik Nordström <henrik_at_henriknordstrom.net>:
> lör 2010-04-03 klockan 23:39 +0300 skrev Mr. Issa(*):
>
>> 2010/03/27 12:26:40| Rebuilding storage in /cache1 (DIRTY)
>> 2010/03/27 12:26:40| Rebuilding storage in /cache2 (DIRTY)
>
> Looks like you did not allow Squid to shut down cleanly before.
>
>> 2010/03/27 12:27:00|   store_swap_size = 103396892k
>
> So there is 103 GB on-disk cache Squid knows about from it's indexes..
> which seem to be considerably less than what's in your cache
> directories.
>
>> Also today i did find this in the cache.log
>>  2010/03/27 00:43:43| storeUpdateCopy: Aborted at 24617 (0)
>
> Unrelated and harmless.
>
>> Every day the cache is decreasing about 10GB or more.
>
> What does cachemgr say about cache usage?
>
> A guess is that the index only got partially saved when you shut down
> Squid earlier causing a lot of objects to get forgotten, and that the
> background cleaner job is now slowly removing unknown objects from the
> cache directories.
>
> Regards
> Henrik
>
>
Received on Sun Apr 04 2010 - 07:44:26 MDT

This archive was generated by hypermail 2.2.0 : Mon Apr 05 2010 - 12:00:03 MDT