[squid-users] squid: Memory utilization higher than expected since moving from 3.3 to 3.4 and Vary: working

From: Martin Sperl <Martin.Sperl_at_amdocs.com>
Date: Mon, 7 Jul 2014 08:46:51 +0000

Hi!

We have found out that since we moved from squid 3.3 to 3.4.3 (and the corresponding Vary) the memory utilization of squid has increased.
It is 10GB right now 9.6G in memory, but we have only configured 4GB for in Memory caching.

Here the ps line:
squid 17695 10.9 61.2 10629864 10001520 ? Rl Apr21 12131:59 (squid-1) -f /opt/squid/squid.conf

Any Ideas what that could be? See below the fine details from mgr:...

BTW: I know it is not the latest version, but I am unsure if there have been any fixes for this behavior in a later version...

Thanks,
                Martin

P.s: the relevant config-section for memory settings:

# define the memory cache as 4GB
cache_mem 4096 MB

# and in memory sizes for single objects:
maximum_object_size 32 KB
maximum_object_size_in_memory 32 KB

# define a disk cache (preferably on ram-disk to avoid IOs)
cache_dir aufs /var/spool/squid/ 8192 16 256

here the infos from:

Mgr:info:
Squid Object Cache: Version 3.4.3
Build Info:
Start Time: Mon, 21 Apr 2014 08:31:27 GMT
Current Time: Mon, 07 Jul 2014 08:21:22 GMT
Connection information for squid:
        Number of clients accessing cache: 0
        Number of HTTP requests received: 998061101
        Number of ICP messages received: 0
        Number of ICP messages sent: 0
        Number of queued ICP replies: 0
        Number of HTCP messages received: 0
        Number of HTCP messages sent: 0
        Request failure ratio: 0.00
        Average HTTP requests per minute since start: 9002.1
        Average ICP messages per minute since start: 0.0
        Select loop called: 7233613675 times, 0.920 ms avg
Cache information for squid:
        Hits as % of all requests: 5min: 40.8%, 60min: 45.5%
        Hits as % of bytes sent: 5min: 50.7%, 60min: 51.6%
        Memory hits as % of hit requests: 5min: 72.6%, 60min: 74.9%
        Disk hits as % of hit requests: 5min: 1.8%, 60min: 2.0%
        Storage Swap size: 7549744 KB
        Storage Swap capacity: 90.0% used, 10.0% free
        Storage Mem size: 4153612 KB
        Storage Mem capacity: 99.0% used, 1.0% free
        Mean Object Size: 5.14 KB
        Requests given to unlinkd: 0
Median Service Times (seconds) 5 min 60 min:
        HTTP Requests (All): 0.00179 0.00091
        Cache Misses: 0.27332 0.23230
        Cache Hits: 0.00000 0.00000
        Near Hits: 0.00286 0.00286
        Not-Modified Replies: 0.00000 0.00000
        DNS Lookups: 0.00094 0.00094
        ICP Queries: 0.00000 0.00000
Resource usage for squid:
        UP Time: 6652194.459 seconds
        CPU Time: 727888.282 seconds
        CPU Usage: 10.94%
        CPU Usage, 5 minute avg: 2.76%
        CPU Usage, 60 minute avg: 2.93%
        Process Data Segment Size via sbrk(): 10517816 KB
        Maximum Resident Size: 40036704 KB
        Page faults with physical i/o: 2100678
Memory usage for squid via mallinfo():
        Total space in arena: -2064964 KB
        Ordinary blocks: 2047465 KB 161900 blks
        Small blocks: 0 KB 0 blks
        Holding blocks: 38432 KB 9 blks
        Free Small blocks: 0 KB
        Free Ordinary blocks: 81875 KB
        Total in use: 81875 KB -4%
        Total free: 81875 KB -4%
        Total size: -2026532 KB
Memory accounted for:
        Total accounted: 1269447 KB -63%
        memPool accounted: 9658055 KB -477%
        memPool unaccounted: -11684587 KB -0%
        memPoolAlloc calls: 507567155336
        memPoolFree calls: 508713005568
File descriptor usage for squid:
        Maximum number of file descriptors: 65536
        Largest file desc currently in use: 1351
        Number of file desc currently in use: 249
        Files queued for open: 0
        Available number of file descriptors: 65287
        Reserved number of file descriptors: 100
        Store Disk files open: 0
Internal Data Structures:
        1477933 StoreEntries
        851676 StoreEntries with MemObjects
        851675 Hot Object Cache Items
        1470120 on-disk objects

Mgr:mem:
Current memory usage:
Pool Obj Size Chunks Allocated In UseIdle Allocations Saved Rate
         (bytes) KB/ch obj/ch (#) used free part %Frag (#) (KB) high (KB) high (hrs) %Tot (#) (KB) high (KB) high (hrs) %alloc (#) (KB) high (KB) (#) %cnt %vol (#)/sec
mem_node 4136 1038636 4195116 4195359538.01 43.434 1038434 4194300 4195359 538.01 99.981 202 816 1564 695940913 0.137 1.2200.499
4K Buffer 4096 471762 1887048 1916096 61.2219.538 471750 1887000 1916096 61.22 99.997 12 48 3120 986312276 0.194 1.713 0.707
Short Strings 40 20241644 790690 794615 61.01 8.18620241331 790677 794615 61.01 99.998 313 13 841 -2147483648 66.374 5.726 240.914
HttpHeaderEntry 56 9903143 541579 544664 61.01 5.6079902997 541571 544664 61.01 99.999 146 8 551 -2147483648 16.522 1.996 60.070
2K Buffer 2048 238817 477634 724132 967.29 4.945 238800 477600 724132 967.29 99.993 17 34 546 -2147483648 1.566 6.917 5.673
16K Buffer 16384 25372 405952 1106704 1357.164.203 25355 405680 1106704 1357.16 99.933 17 272 4048 268150503 0.053 1.863 0.193
HttpReply 280 851758 232903 233312 67.89 2.411 851732 232896 233312 67.89 99.997 26 8 138 -2147483648 0.688 0.415 2.495
8K Buffer 8192 27681 221448 275280 1357.54 2.29327679 221432 275280 1357.54 99.993 2 16 312 235405729 0.046 0.818 0.168
MemObject 240 851740 199627 199973 67.89 2.067 851731 199625 199973 67.89 99.999 9 3 93 492884384 0.097 0.050 0.354
StoreEntry 120 1477969 173200 173405 69.33 1.7931477949 173198 173405 69.33 99.999 20 3 32 448740915 0.088 0.023 0.322
Medium Strings 128 1262162 157771 160057 61.01 1.6331262100 157763 160057 61.01 99.995 62 8 279 -2147483648 4.731 1.306 17.148
cbdata BodyPipe (43) 152 765008 113556 114424 68.08 1.176 765004 113556 114424 68.08 99.999 4 1 34 358799947 0.071 0.023 0.257
HttpHdrCc 96 769579 72149 72667 59.52 0.747 769566 72147 72667 59.52 99.998 13 2 34 1594117469 0.313 0.065 1.138
LRU policy node 24 2321816 54418 54496 68.09 0.5632321811 54418 54496 68.09 100.000 5 1 12 159292188 0.031 0.002 0.117
cbdata MemBuf (13) 64 851759 53235 53330 67.89 0.551 851734 53234 53330 67.89 99.997 25 2 33 -2147483648 0.923 0.127 3.346
32K Buffer 32768 1603 51296 111520 979.75 0.531 160051200 111520 979.75 99.813 3 96 736 20665690 0.004 0.287 0.015
MD5 digest 16 1477969 23094 23121 69.33 0.2391477949 23093 23121 69.33 99.999 20 1 5 595307879 0.117 0.004 0.426
Long Strings 512 6736 3368 7858 1063.01 0.0356699 3350 7858 1063.01 99.451 37 19 234 -2147483648 1.034 1.142 3.750
64K Buffer 65536 46 2944 33792 1711.70 0.0300 0 33792 1711.70 0.000 46 2944 32768 -2147483648 0.466 65.894 1.691
acl_ip_data 96 5725 537 537 1848.01 0.0065725 537 537 1848.01 100.000 0 0 1 276 0.000 0.000 0.000
cbdata IdleConnList (16) 4160 51 208 281 1757.200.002 45 183 281 1757.20 88.235 6 25 86 36686446 0.007 0.065 0.026
cbdata clientReplyContext (23) 4320 31 131 1730 1293.490.001 4 17 1730 1293.49 12.903 27 114 1321 995516255 0.196 1.823 0.711
cbdata ClientSocketContext (22) 4256 31 129 1705 1293.490.001 4 17 1705 1293.49 12.903 27 113 1301 995516208 0.196 1.796 0.711
HttpRequest 1768 63 109 1428 1293.49 0.0017 13 1428 1293.49 11.111 56 97 992 -2147483648 0.827 3.153 2.998
cbdata ConnStateData (20) 440 201 87 1259 390.81 0.001171 74 1259 390.81 85.075 30 13 343 528103233 0.104 0.099 0.381
Comm::Connection 192 247 47 591 390.81 0.000 21741 591 390.81 87.854 30 6 171 829565512 0.163 0.068 0.596
ipcache_entry 128 289 37 82 1252.79 0.000288 36 82 1252.79 99.654 1 1 49 821666 0.000 0.000 0.001
cbdata idns_query (9) 8696 3 26 3661 1252.79 0.0000 0 3661 1252.79 0.000 3 26 3346 1134547 0.000 0.004 0.001
Acl::AndNode 136 184 25 25 1848.01 0.000184 25 25 1848.01 100.000 0 0 0 0 0.000 0.000 0.000
MimeEntry 128 177 23 23 1848.01 0.000177 23 23 1848.01 100.000 0 0 0 0 0.000 0.000 0.000
fqdncache_entry 160 99 16 16 11.53 0.000 9916 16 11.53 100.000 0 0 1 607 0.000 0.000 0.000
cbdata ClientHttpRequest (21) 408 31 13 164 1293.490.000 4 2 164 1293.49 12.903 27 11 125 995516208 0.196 0.172 0.711
4KB Strings 4096 3 12 100 136.37 0.000 00 100 136.37 0.000 3 12 100 4568442 0.001 0.008 0.003
cbdata ServiceRep (15) 344 34 12 12 1848.01 0.00034 12 12 1848.01 100.000 0 0 0 0 0.000 0.000 0.000
cbdata Tree (6) 192 52 10 10 1848.01 0.00052 10 10 1848.01 100.000 0 0 0 0 0.000 0.000 0.000
cbdata ModXact (30) 496 17 9 127 1711.70 0.0000 0 127 1711.70 0.000 17 9 126 1177041017 0.231 0.247 0.839
squidaio_small_bufs 4096 2 8 120 1065.11 0.0000 0 120 1065.11 0.000 2 8 120 60491040 0.012 0.105 0.043
cbdata clientStreamNode (24) 128 62 8 103 1293.490.000 8 1 103 1293.49 12.903 54 7 79 1991032510 0.391 0.108 1.421
cbdata OptXact (32) 312 19 6 11 885.88 0.000 00 11 885.88 0.000 19 6 11 7038032 0.001 0.001 0.005
RegexList 88 59 6 6 1848.01 0.00059 6 6 1848.01 100.000 0 0 0 0 0.000 0.000 0.000
ACLStrategised 136 38 6 6 1848.01 0.00038 6 6 1848.01 100.000 0 0 0 0 0.000 0.000 0.000
ACLStrategised 136 37 5 5 1848.01 0.00037 5 5 1848.01 100.000 0 0 0 0 0.000 0.000 0.000
HttpHdrScTarget 88 55 5 6 343.75 0.000 555 6 343.75 100.000 0 0 2 149 0.000 0.000 0.000
cbdata Logfile (11) 4192 1 5 5 1848.01 0.0001 5 5 1848.01 100.000 0 0 0 0 0.000 0.000 0.000
cbdata store_client (34) 160 23 4 117 1293.490.000 4 1 117 1293.49 17.391 19 3 76 1290240791 0.254 0.088 0.920
1KB Strings 1024 3 3 55 412.45 0.000 00 55 412.45 0.000 3 3 38 50912098 0.010 0.022 0.037
cbdata HttpStateData (38) 304 9 3 115 1293.490.000 2 1 115 1293.49 22.222 7 3 76 190925179 0.038 0.025 0.137
cbdata Iterator (28) 160 17 3 40 1711.70 0.0000 0 40 1711.70 0.000 17 3 40 1177188448 0.231 0.080 0.839
ACLSourceIP 120 22 3 3 1848.01 0.00022 3 3 1848.01 100.000 0 0 0 0 0.000 0.000 0.000
cbdata ModXactLauncher (29) 152 17 3 38 1711.700.000 0 0 38 1711.70 0.000 17 3 38 1177189213 0.231 0.076 0.839
Acl::NotNode 136 18 3 3 1848.01 0.00018 3 3 1848.01 100.000 0 0 0 0 0.000 0.000 0.000
cbdata AccessCheck (27) 144 17 3 41 1711.69 0.0000 0 41 1711.69 0.000 17 3 41 1177394228 0.231 0.072 0.839
cbdata OptXactLauncher (31) 128 19 3 5 885.88 0.0000 0 5 885.88 0.000 19 3 5 7037587 0.001 0.000 0.005
ev_entry 48 47 3 3 1831.15 0.00045 3 3 1831.15 95.745 2 1 2 33129146 0.007 0.001 0.024
ACLHTTPHeaderData 48 40 2 2 1848.01 0.00040 2 2 1848.01 100.000 0 0 0 0 0.000 0.000 0.000
cbdata ClientRequestContext (25) 104 18 2 30 1711.70 0.000 0 0 30 1711.70 0.000 18 2 30 988402315 0.194 0.044 0.705
ACLRegexData 16 110 2 2 1848.01 0.000110 2 2 1848.01 100.000 0 0 0 0 0.000 0.000 0.000
cbdata FwdState (36) 168 9 2 65 1293.49 0.0002 1 65 1293.49 22.222 7 2 42 191697095 0.038 0.014 0.137
cbdata ACLFilledChecklist (26) 440 3 2 93 1252.790.000 1 1 93 1252.79 33.333 2 1 85 -2147483648 2.155 2.045 7.805
cbdata ConnOpener (33) 136 6 1 27 1711.70 0.0000 0 27 1711.70 0.000 6 1 27 66249937 0.013 0.004 0.048
cbdata PortCfg (2) 344 2 1 1 1848.01 0.0002 1 1 1848.01 100.000 0 0 0 0 0.000 0.000 0.000
ACLStrategised 136 5 1 1 1848.01 0.0005 1 1 1848.01 100.000 0 0 0 0 0.000 0.000 0.000
aio_thread 40 16 1 1 1847.93 0.00016 1 1 1847.93 100.000 0 0 0 0 0.000 0.000 0.000
squidaio_micro_bufs 128 5 1 14 1065.11 0.0000 0 14 1065.11 0.000 5 1 14 176721246 0.035 0.010 0.126
aio_ctrl 112 5 1 13 1065.11 0.0000 0 13 1065.11 0.000 5 1 13 237358432 0.047 0.011 0.169
ACLStrategised 136 4 1 1 1848.01 0.0004 1 1 1848.01 100.000 0 0 0 0 0.000 0.000 0.000
cbdata CbDataList (3) 40 13 1 1 1848.01 0.00013 1 1 1848.01 100.000 0 0 0 0 0.000 0.000 0.000
aio_request 104 5 1 12 1065.11 0.0000 0 12 1065.11 0.000 5 1 12 237365801 0.047 0.010 0.169
cbdata ErrorState (46) 240 2 1 3 1497.43 0.0000 0 3 1497.43 0.000 2 1 3 10391751 0.002 0.001 0.007
ACLStrategised 136 3 1 1 1848.01 0.0003 1 1 1848.01 100.000 0 0 0 0 0.000 0.000 0.000
cbdata CbDataList (1) 40 10 1 1 1848.01 0.00010 1 1 1848.01 100.000 0 0 0 0 0.000 0.000 0.000
cbdata CbDataList (47) 96 4 1 4 1664.29 0.0000 0 4 1664.29 0.000 4 1 4 27953666 0.005 0.001 0.020
acl_name_list 72 5 1 1 1848.01 0.0005 1 1 1848.01 100.000 0 0 0 0 0.000 0.000 0.000
ACLDestinationIP 120 3 1 1 1848.01 0.0003 1 1 1848.01 100.000 0 0 0 0 0.000 0.000 0.000
cbdata UFSStoreState (39) 176 2 1 13 1065.110.000 0 0 13 1065.11 0.000 2 1 13 112646684 0.022 0.008 0.080
ACLDomainData 16 19 1 1 1848.01 0.00019 1 1 1848.01 100.000 0 0 0 0 0.000 0.000 0.000
cbdata CbDataList (4) 64 4 1 1 1848.01 0.0004 1 1 1848.01 100.000 0 0 0 0 0.000 0.000 0.000
cbdata ps_state (37) 248 1 1 1 1835.63 0.0000 0 1 1835.63 0.000 1 1 1 192773573 0.038 0.020 0.137
ACLCertificateData 72 3 1 1 1848.01 0.0003 1 1 1848.01 100.000 0 0 0 0 0.000 0.000 0.000
cbdata RemovalPolicy (7) 104 2 1 1 1848.010.000 2 1 1 1848.01 100.000 0 0 0 0 0.000 0.000 0.000
cbdata StoreSearchHashIndex (18) 104 2 1 1 1848.01 0.000 1 1 1 1848.01 50.000 1 1 1 20 0.000 0.000 0.000
cbdata TcpAcceptor (17) 88 2 1 1 1848.01 0.0002 1 1 1848.01 100.000 0 0 0 0 0.000 0.000 0.000
cbdata DiskThreadsDiskFile (40) 88 2 1 7 1065.110.000 0 0 7 1065.11 0.000 2 1 7 112646684 0.022 0.004 0.080
AclDenyInfoList 32 5 1 1 1848.01 0.0005 1 1 1848.01 100.000 0 0 0 0 0.000 0.000 0.000
HttpHdrRange 32 5 1 3 339.96 0.000 21 3 339.96 40.000 3 1 1 1563142 0.000 0.000 0.001
cbdata ReadRequest (41) 72 2 1 3 1065.11 0.0000 0 3 1065.11 0.000 2 1 3 60491040 0.012 0.002 0.043
ACLStrategised 136 1 1 1 1848.01 0.0001 1 1 1848.01 100.000 0 0 0 0 0.000 0.000 0.000
UFSStoreState::_queued_write 32 4 1 3 1428.470.000 0 0 3 1428.47 0.000 4 1 3 134435143 0.026 0.002 0.096
HttpHdrContRange 24 5 1 2 1664.29 0.0000 0 2 1664.29 0.000 5 1 2 792627 0.000 0.000 0.001
ACLStringData 16 6 1 1 1848.01 0.0006 1 1 1848.01 100.000 0 0 0 0 0.000 0.000 0.000
ACLSslErrorData 16 6 1 1 1848.01 0.0006 1 1 1848.01 100.000 0 0 0 0 0.000 0.000 0.000
cbdata generic_cbdata (35) 32 3 1 14 1252.790.000 0 0 14 1252.79 0.000 3 1 13 65234012 0.013 0.001 0.047
UFSStoreState::_queued_read 40 2 1 2 1065.110.000 0 0 2 1065.11 0.000 2 1 2 46057286 0.009 0.001 0.033
cbdata IoResult (42) 40 2 1 2 1065.11 0.0000 0 2 1065.11 0.000 2 1 2 60491040 0.012 0.001 0.043
cbdata WriteRequest (44) 80 1 1 1 1847.930.000 0 0 1 1847.93 0.000 1 1 1 134753572 0.026 0.005 0.096
HttpHdrRangeSpec 16 5 1 2 339.96 0.000 21 2 339.96 40.000 3 1 1 1563133 0.000 0.000 0.001
ACLUserData 24 3 1 1 1848.01 0.0003 1 1 1848.01 100.000 0 0 0 0 0.000 0.000 0.000
StoreSwapLogData 72 1 1 1 1848.01 0.0000 0 1 1848.01 0.000 1 1 1 129809816 0.026 0.004 0.092
cbdata RemovalPurgeWalker (19) 72 1 1 1 1848.010.000 0 0 1 1848.01 0.000 1 1 1 7712019 0.002 0.000 0.006
ACLMethodData 16 4 1 1 1848.01 0.0004 1 1 1848.01 100.000 0 0 0 0 0.000 0.000 0.000
link_list 16 4 1 2 1065.11 0.0000 0 2 1065.11 0.000 4 1 2 180627075 0.036 0.001 0.129
dwrite_q 48 1 1 1 1848.01 0.0000 0 1 1848.01 0.000 1 1 1 264625573 0.052 0.005 0.188
ACLNoteData 40 1 1 1 1848.01 0.0001 1 1 1848.01 100.000 0 0 0 0 0.000 0.000 0.000
cbdata CbDataList (5) 40 1 1 1 1848.01 0.0001 1 1 1848.01 100.000 0 0 0 0 0.000 0.000 0.000
cbdata IoResult (45) 40 1 1 1 1847.93 0.0000 0 1 1847.93 0.000 1 1 1 134753572 0.026 0.002 0.096
ACLASN 16 2 1 1 1848.01 0.0002 1 1 1848.01 100.000 0 0 0 0 0.000 0.000 0.000
ACLHierCodeData 32 1 1 1 1848.01 0.0001 1 1 1848.01 100.000 0 0 0 0 0.000 0.000 0.000
ACLProtocolData 16 2 1 1 1848.01 0.0002 1 1 1848.01 100.000 0 0 0 0 0.000 0.000 0.000
ACLTimeData 32 1 1 1 1848.01 0.0001 1 1 1848.01 100.000 0 0 0 0 0.000 0.000 0.000
CacheDigest 32 1 1 1 1848.01 0.0001 1 1 1848.01 100.000 0 0 0 0 0.000 0.000 0.000
wordlist 16 2 1 1 1848.01 0.0002 1 1 1848.01 100.000 0 0 1 169 0.000 0.000 0.000
StoreMetaMD5 32 1 1 1 1847.93 0.0000 0 1 1847.93 0.000 1 1 1 110536338 0.022 0.001 0.079
StoreMetaSTDLFS 32 1 1 1 1847.93 0.0000 0 1 1847.93 0.000 1 1 1 110536338 0.022 0.001 0.079
StoreMetaURL 32 1 1 1 1847.93 0.0000 0 1 1847.93 0.000 1 1 1 110536338 0.022 0.001 0.079
StoreMetaObjSize 32 1 1 1 1847.93 0.0000 0 1 1847.93 0.000 1 1 1 110535723 0.022 0.001 0.079
StoreMetaVary 32 1 1 1 1847.93 0.0000 0 1 1847.93 0.000 1 1 1 6413952 0.001 0.000 0.005
FwdServer 24 1 1 1 1835.63 0.0000 0 1 1835.63 0.000 1 1 1 192773573 0.038 0.002 0.137
16KB Strings 16384 0 0 32 853.17 0.000 00 32 853.17 -1.000 0 0 32 0 0.000 0.000 0.000
cbdata nsvc (8) 72 0 0 1 1819.31 0.0000 0 1 1819.31 -1.000 0 0 1 0 0.000 0.000 0.000
cbdata RebuildState (12) 688 0 0 1 1848.010.000 0 0 1 1848.01 -1.000 0 0 1 0 0.000 0.000 0.000
cbdata RemovalPolicyWalker (48) 56 0 0 1 1846.340.000 0 0 1 1846.34 -1.000 0 0 1 0 0.000 0.000 0.000
cbdata BodySink (49) 80 0 0 1 1844.65 0.0000 0 1 1844.65 -1.000 0 0 1 549 0.000 0.000 0.000
HttpHdrSc 16 0 0 1 343.78 0.000 00 1 343.78 -1.000 0 0 1 82 0.000 0.000 0.000
Total 1 42593287 9658537 971909061.01 100.000 42591806 9653779 9713153 61.04 99.951 1481 4758 37935 -2147483648 99.766 99.807 362.183
Cumulative allocated volume: 235.8852 TB
Current overhead: 34522 bytes (0.000%)
Idle pool limit: 5.00 MB
Total Pools created: 134
Pools ever used: 123 (shown above)
Currently in use: 78
String Pool Impact
         (%strings) (%volume)
Short Strings 94 83
Medium Strings 6 17
Long Strings 0 0
1KB Strings 0 0
4KB Strings 0 0
16KB Strings 0 0
Other Strings 0 0

Large buffers: 0 (0 KB)

This message and the information contained herein is proprietary and confidential and subject to the Amdocs policy statement,
you may review at http://www.amdocs.com/email_disclaimer.asp
Received on Mon Jul 07 2014 - 08:47:01 MDT

This archive was generated by hypermail 2.2.0 : Mon Jul 07 2014 - 12:00:04 MDT