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

Hey Martin,

I just opened a bug-report on a similar issue which there is a
possibility that this is a duplicate of yours.
http://bugs.squid-cache.org/show_bug.cgi?id=4083

I have a tiny reverse proxy server with no Vary used at all on it.
I am using squid 3.4.5-2 on it(my RPM).
I did noticed the memory leak and I think that I can provide a testing
environment easily enough that will reproduce the same issue.

Do you compile squid yourself or using some sort of binary package?
If you are using RPM on CentOS or Oracle linux I can provide you with an
alternative RPM which will have valgrind support and will might be able
to get us more information.

Indeed your system leaks and badly... but I think it will be very simple
to reproduce even on a small scaled system with a period of 48-72 hours
up-time of the service.

I will try to add into the bug-report data that I will collect such as
mgr:info, mgr:mem, mgr:filedescriptors

Eliezer

On 07/08/2014 01:20 PM, Martin Sperl wrote:
> The problem is that it is a "slow" leak - it takes some time (month) to find it...
> Also it only happens on real live traffic with high volume plus high utilization of "Vary:"
> Moving our prod environment to head would be quite a political issue inside our organization.
> Arguing to go to the latest stable version 3.4.6 would be possible, but I doubt it would change a thing
>
> In the meantime we have not restarted the squids yet, so we still got a bit of information available if needed.
> But we cannot keep it up in this state much longer.
>
> I created a core-dump, but analyzing that is hard.
>
> Here the top strings from that 10GB core-file - taken via: strings corefile| sort | uniq -c | sort -rn | head -20).
> This may give you some idea:
> 2071897 =0.7
> 1353960 Keep-Alive
> 1343528 image/gif
> 877129 HTTP/1.1 200 OK
> 855949 GMT
> 852122 Content-Type
> 851706 HTTP/
> 851371 Date
> 850485 Server
> 848027 IEND
> 821956 Content-Length
> 776359 Content-Type: image/gif
> 768935 Cache-Control
> 760741 ETag
> 743341 live
> 720255 Connection
> 677920 Connection: Keep-Alive
> 676108 Last-Modified
> 662765 Expires
> 585139 X-Powered-By: Servlet/2.4 JSP/2.0
>
> Another thing I thought we could do is:
> * restart squids
> * run mgr:mem every day and compare the daily changes for all the values (maybe others?)
>
> Any other ideas how to "find" the issue?
>
> Martin
>
>
>
>
> -----Original Message-----
> From: Amos Jeffries [mailto:squid3_at_treenet.co.nz]
> Sent: Dienstag, 08. Juli 2014 11:40
> To: squid-users_at_squid-cache.org
> Subject: RE: [squid-users] squid: Memory utilization higher than expected since moving from 3.3 to 3.4 and Vary: working
>
> On 2014-07-08 19:38, Martin Sperl wrote:
>> Well - there are 4 Points here:
>> a) this is gradual behavior that takes month to accumulate
>> b) extra used memory is much bigger than Cache (1.5x aprox), which
>> looks wrong to me as the other parameters you have given
>> (diskcache,...) are not
>> c) we have not seen this behavior with 3.3 and have just switched to
>> 3.4 two month ago and it is running since then showing this increase.
>> d) if you look at the memory report (mgr:mem) which I have shared you
>> find: 900MB for 542k HttpHeaderEntries and 2GB for 791k Short_Strings
>> - and that is almost 3 out of 4.2G for this report alone.
>>
>> So I was guessing there was some sort of memory allocation bug or
>> something - maybe something to do with the now working handling of
>> "vary" headers, that triggers this memory leak.
>> To me it looks as if those "Vary" nodes are not clean up properly and
>> that is why we are slowly increasing memory...
>>
>
> Hmm. Yes that does sound like what we call a pseudo-leak (same effects
> as a memory leak, but not an actual leak since the objects are still
> being reference-counted by something). The headers and HttpHeaderEntries
> are stored as collections of String's. The HttpHeaderEntries are
> ref-counted objects used by HttpRequest and HttpReply transaction
> objects, which are themselves ref-counted. If there are a lot of those
> being held onto for no reason this needs to be tracked down.
>
> Are you in a position to test the 3.HEAD code to see if it is something
> we fixed already there or a new issue to debug from scratch?
>
>
>> There are specially a few things in the msg:info block that made me
>> suspicious:
>> 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
>> Especially those negative Numbers and percentages - but maybe that is
>> just a reporting bug, which - if so - is hindering debugging the real
>> thing
>
> 64-bit mallinfo() bugs produce corrupt output. The only uncorrupted
> values above are the memPool accounted KB size and probably the "calls"
> counts.
>
>
>>
>> Thanks,
>> Martin
>>
>> P.s: it would be helpful if the output of mgr:mem would be formatted
>> in a way that would allow it to get easily pasted into Excel or
>> similar - no spaces in pool names would be sufficient...
>>
>
> The report is a TSV spreadsheet. If you save it directly to a file then
> import into Excel selecting Tab separator instead of the default comma
> (CSV) it loads as a nice spreadsheet.
>
> Amos
>
>
> 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 Fri Jul 11 2014 - 06:33:14 MDT