Varnish 2.0.3 consuming excessive memory
Darryl Dixon - Winterhouse Consulting
darryl.dixon at winterhouseconsulting.com
Wed Apr 8 05:21:10 CEST 2009
Further to this, I just ran the pmap on the runaway process again (roughly
15 minutes since last time), and the large ~2GB allocation has jumped by
about 60MB in that time, eg:
------------------------------------------------------
3940: /u01/app/varnish/sbin/varnishd -a web-cms-edit1.prd.internal:8080
web-cms-edit.prd.internal:8080 -T web-cms-edit1.prd.internal:18080 -t 3600
-f /u01/data/prd-edit/varnish/vcl.conf -s
file,/u01/data/prd-edit/varnish/storage.cache,256M -n
/u01/data/prd-edit/varnish/state -P
/u01/data/prd-edit/varnish/varnishd.pid
Address Kbytes RSS Anon Locked Mode Mapping
0000000000400000 312 - - - r-x-- varnishd
000000000064d000 8 - - - rw--- varnishd
000000000064f000 68 - - - rw--- [ anon ]
0000000040000000 4 - - - ----- [ anon ]
0000000040001000 10240 - - - rw--- [ anon ]
[...snip...]
00002aaab0900000 262144 - - - rw-s- storage.cache
00002aaac0900000 28 - - - r-x-- vcl.1P9zoqAU.so
00002aaac0907000 2048 - - - ----- vcl.1P9zoqAU.so
00002aaac0b07000 8 - - - rw--- vcl.1P9zoqAU.so
00002aaac0c00000 2056 - - - rw--- [ anon ]
00002aaac0f00000 2052 - - - rw--- [ anon ]
00002aaac1200000 233476 - - - rw--- [ anon ]
00002aaacf700000 2403328 - - - rw--- [ anon ]
00007fff4b619000 84 - - - rw--- [ stack ]
ffffffffff600000 8192 - - - ----- [ anon ]
---------------- ------ ------ ------ ------
total kB 3187344 - - -
------------------------------------------------------
...And in the time it's taken me to compose this mail it's grown by
another 20MB:
------------------------------------------------------
00002aaacf700000 2418688 - - - rw--- [ anon ]
------------------------------------------------------
...so it is a pretty consistent, continuous upwards trend in terms of
memory usage...
regards,
Darryl Dixon
Winterhouse Consulting Ltd
http://www.winterhouseconsulting.com
>> Not that I have an answer, but I'd be curious to see the differences
>> in 'pmap -x <pid>' output for the different children.
>>
>> --Michael
>>
>
> That's a good thought - I'd almost forgotten about pmap. Anyhow, the
> 'normal' process is set up with a 2GB storage cache and pmap shows pretty
> much what you would expect - the largest anonymous segment is 41MB, with
> the vast majority of allocated memory booked against storage.cache (2GB).
> The pmap for the 'runaway' process shows 256MB booked against
> storage.cache, and then one of the an anonymous allocations is 2.3GB. For
> example:
>
>
> Normal process:
> ------------------------------------------------------
> 3896: /u01/app/varnish/sbin/varnishd -a web-cms1.prd.internal:8080
> web-cms.prd.internal:8080 -T web-cms1.prd.internal:18080 -t 108000 -f
> /u01/data/prd/varnish/vcl.conf -s
> file,/u01/data/prd/varnish/storage.cache,2048M -n
> /u01/data/prd/varnish/state -P /u01/data/prd/varnish/varnishd.pid
> Address Kbytes RSS Anon Locked Mode Mapping
> 0000000000400000 312 - - - r-x-- varnishd
> 000000000064d000 8 - - - rw--- varnishd
> 000000000064f000 68 - - - rw--- [ anon ]
> 0000000040000000 4 - - - ----- [ anon ]
> 0000000040001000 10240 - - - rw--- [ anon ]
> [...snip...]
> 00002aaab0900000 2097152 - - - rw-s- storage.cache
> 00002aab30900000 28 - - - r-x-- vcl.1P9zoqAU.so
> 00002aab30907000 2044 - - - ----- vcl.1P9zoqAU.so
> 00002aab30b06000 8 - - - rw--- vcl.1P9zoqAU.so
> 00002aab30c00000 2056 - - - rw--- [ anon ]
> 00002aab30f00000 2056 - - - rw--- [ anon ]
> 00002aab31200000 41984 - - - rw--- [ anon ]
> 00007fffae8f2000 88 - - - rw--- [ stack ]
> ffffffffff600000 8192 - - - ----- [ anon ]
> ---------------- ------ ------ ------ ------
> total kB 2468512 - - -
> ------------------------------------------------------
>
>
>
> Runaway process:
> ------------------------------------------------------
> 3940: /u01/app/varnish/sbin/varnishd -a web-cms-edit1.prd.internal:8080
> web-cms-edit.prd.internal:8080 -T web-cms-edit1.prd.internal:18080 -t 3600
> -f /u01/data/prd-edit/varnish/vcl.conf -s
> file,/u01/data/prd-edit/varnish/storage.cache,256M -n
> /u01/data/prd-edit/varnish/state -P
> /u01/data/prd-edit/varnish/varnishd.pid
> Address Kbytes RSS Anon Locked Mode Mapping
> 0000000000400000 312 - - - r-x-- varnishd
> 000000000064d000 8 - - - rw--- varnishd
> 000000000064f000 68 - - - rw--- [ anon ]
> 0000000040000000 4 - - - ----- [ anon ]
> 0000000040001000 10240 - - - rw--- [ anon ]
> [...snip...]
> 00002aaab0900000 262144 - - - rw-s- storage.cache
> 00002aaac0900000 28 - - - r-x-- vcl.1P9zoqAU.so
> 00002aaac0907000 2048 - - - ----- vcl.1P9zoqAU.so
> 00002aaac0b07000 8 - - - rw--- vcl.1P9zoqAU.so
> 00002aaac0c00000 2056 - - - rw--- [ anon ]
> 00002aaac0f00000 2052 - - - rw--- [ anon ]
> 00002aaac1200000 233476 - - - rw--- [ anon ]
> 00002aaacf700000 2337792 - - - rw--- [ anon ]
> 00007fff4b619000 84 - - - rw--- [ stack ]
> ffffffffff600000 8192 - - - ----- [ anon ]
> ---------------- ------ ------ ------ ------
> total kB 3121808 - - -
> ------------------------------------------------------
>
>
> Both processes have been running for the same amount of time - 1day
> 17hours.
>
> regards,
> Darryl Dixon
> Winterhouse Consulting Ltd
> http://www.winterhouseconsulting.com
>
>
>
>> On Apr 7, 2009, at 6:27 PM, Darryl Dixon - Winterhouse Consulting wrote:
>>
>>>> Hi All,
>>>>
>>>> I have an odd problem that I have only noticed happening since
>>>> moving from
>>>> 1.1.2 to 2.0.3 - excessive memory consumption of the varnish child
>>>> process. For example, I have a varnish instance with a 256MB cache
>>>> allocated, that is currently consuming 4.9GB of resident memory
>>>> (6.5GB
>>>> virtual). The instance has only been running for 4 days and has
>>>> only got
>>>> 25MB of objects in the cache.
>>>>
>>>> This is clearly excessive and is causing us some serious problems
>>>> in terms
>>>> of memory pressure on the machine. Our VCL is largely unchanged
>>>> from our
>>>> 1.1.2 setup to the 2.0.3 except for the obvious vcl.syntax changes,
>>>> and
>>>> the introduction of request restarts under certain limited
>>>> scenarios. Can
>>>> anyone shed some light?
>>>>
>>>
>>> One further footnote to this. I have a second varnish instance
>>> running on
>>> the same machine which talks to different backend servers (still
>>> primarily
>>> the same sort of content though), with the VCL only fractionally
>>> different
>>> - it does not seem to suffer from the runaway memory consumption of
>>> the
>>> first instance. The only difference in the VCL between the two is
>>> that in
>>> the one with runaway memory this is present in vcl_recv():
>>>
>>> + if (req.http.Pragma ~ ".*no-cache.*" || req.http.Cache-Control ~
>>> ".*no-cache.*") {
>>> + purge_url(regsub(req.url, "[?].*$", ".*$"));
>>> + }
>>> +
>>>
>>> Is there possibly something in the regsub engine being triggered
>>> that is
>>> very expensive and would cause it to consume and hold on to large
>>> amounts
>>> of memory?
>>>
> _______________________________________________
> varnish-misc mailing list
> varnish-misc at projects.linpro.no
> http://projects.linpro.no/mailman/listinfo/varnish-misc
>
More information about the varnish-misc
mailing list