Re: Varnish 2.0.3 consuming excessive memory
| My understanding of using 'pass' in vcl_hit is that it causes the object | to be marked as 'hit for pass' and therefore is uncacheable from that | point onwards. In fact, pass'ing out of vcl_hit was what I used to do a | while ago, but it caused that exact behaviour (items would no longer be | cached by varnish) so I swapped it for purge_url... You can try setting obj.ttl = 0s and then restart in vcl_hit. I believe that should work. Thanks Tollef - I will try this today and report back. This seems to correct the problem - thanks Tollef! Further to root cause of the original issue: using purge_url seems to result inside EXP_Rearm with the objexp (object expire?) being added unconditionally to the exp_heap binheap, and it's not clear to me where (if ever) this heap is pruned. For example, I see in varnishlog multiple calls to the same URL from the same client with the same headers resulting in multiple unique entries being added to exp_heap, eg: ExpBan c 981217322 was banned [...] ExpBan c 981217323 was banned [...etc...] Where, if anywhere, is exp_heap pruned for entries like this? I couldn't quite make sense of exp_timer() to be certain of under what conditions it actually removes things from this heap - it looks like that function is mainly concerned with items expiring from the Expires http header or similar... regards, Darryl Dixon Winterhouse Consulting Ltd http://www.winterhouseconsulting.com ___ varnish-misc mailing list varnish-misc@projects.linpro.no http://projects.linpro.no/mailman/listinfo/varnish-misc
Re: Varnish 2.0.3 consuming excessive memory
]] Darryl Dixon - Winterhouse Consulting | My understanding of using 'pass' in vcl_hit is that it causes the object | to be marked as 'hit for pass' and therefore is uncacheable from that | point onwards. In fact, pass'ing out of vcl_hit was what I used to do a | while ago, but it caused that exact behaviour (items would no longer be | cached by varnish) so I swapped it for purge_url... You can try setting obj.ttl = 0s and then restart in vcl_hit. I believe that should work. -- Tollef Fog Heen Redpill Linpro -- Changing the game! t: +47 21 54 41 73 ___ varnish-misc mailing list varnish-misc@projects.linpro.no http://projects.linpro.no/mailman/listinfo/varnish-misc
Re: Varnish 2.0.3 consuming excessive memory
| My understanding of using 'pass' in vcl_hit is that it causes the object | to be marked as 'hit for pass' and therefore is uncacheable from that | point onwards. In fact, pass'ing out of vcl_hit was what I used to do a | while ago, but it caused that exact behaviour (items would no longer be | cached by varnish) so I swapped it for purge_url... You can try setting obj.ttl = 0s and then restart in vcl_hit. I believe that should work. Thanks Tollef - I will try this today and report back. regards, Darryl Dixon Winterhouse Consulting Ltd http://www.winterhouseconsulting.com ___ varnish-misc mailing list varnish-misc@projects.linpro.no http://projects.linpro.no/mailman/listinfo/varnish-misc
Re: Varnish 2.0.3 consuming excessive memory
Darryl Dixon - Winterhouse Consulting
darryl.di...@winterhouseconsulting.com writes:
+if (req.http.Pragma ~ .*no-cache.* || req.http.Cache-Control ~
.*no-cache.*) {
+purge_url(regsub(req.url, [?].*$, .*$));
+}
+
It would be interesting to see how often this condition is true...
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?
I don't think so. However, your code will add an entry to the ban list
every time a request that matches the above condition is received, and
this entry will remain on the list until every object that was in the
cache before the entry was added has been requested at least once.
If you really want no-cache to purge the requested object, you should do
it in vcl_hit (set obj.ttl to 0 and pass). Otherwise, you should simply
pass directly from vcl_recv.
DES
--
Dag-Erling Smørgrav - d...@des.no
___
varnish-misc mailing list
varnish-misc@projects.linpro.no
http://projects.linpro.no/mailman/listinfo/varnish-misc
Re: Varnish 2.0.3 consuming excessive memory
hi darryl i had a simlar problem (varnish child process consuming lots of memory) a week ago (see the thread make varnish don't start a subprocess) the solution for my problem seems to be to use a high-enough cache-size: starting varnish with -s file,/tmp/storage,300M will make the child process use *about* 800M RAM (the RES column in top) after some hours. after that i needed to restart varnish to free some ram for my webserver. starting with a bigger cache -s file,/tmp/storage,600M makes it using about 500M RAM (the RES column in top after 5 days of uptime) and happily coexist with zope ;-) maybe this helps you too. regards, fRiSi Am Mittwoch, 8. April 2009 05:05:36 schrieb Darryl Dixon - Winterhouse Consulting: 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 RSSAnon Locked Mode Mapping 0040 312 - - - r-x-- varnishd 0064d000 8 - - - rw--- varnishd 0064f000 68 - - - rw---[ anon ] 4000 4 - - - -[ anon ] 40001000 10240 - - - rw---[ anon ] [...snip...] 2aaab090 2097152 - - - rw-s- storage.cache 2aab3090 28 - - - r-x-- vcl.1P9zoqAU.so 2aab309070002044 - - - - vcl.1P9zoqAU.so 2aab30b06000 8 - - - rw--- vcl.1P9zoqAU.so 2aab30c02056 - - - rw---[ anon ] 2aab30f02056 - - - rw---[ anon ] 2aab3120 41984 - - - rw---[ anon ] 7fffae8f2000 88 - - - rw---[ stack ] ff608192 - - - -[ 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 RSSAnon Locked Mode Mapping 0040 312 - - - r-x-- varnishd 0064d000 8 - - - rw--- varnishd 0064f000 68 - - - rw---[ anon ] 4000 4 - - - -[ anon ] 40001000 10240 - - - rw---[ anon ] [...snip...] 2aaab090 262144 - - - rw-s- storage.cache 2aaac090 28 - - - r-x-- vcl.1P9zoqAU.so 2aaac09070002048 - - - - vcl.1P9zoqAU.so 2aaac0b07000 8 - - - rw--- vcl.1P9zoqAU.so 2aaac0c02056 - - - rw---[ anon ] 2aaac0f02052 - - - rw---[ anon ] 2aaac120 233476 - - - rw---[ anon ] 2aaacf70 2337792 - - - rw---[ anon ] 7fff4b619000 84 - - - rw---[ stack ] ff608192 - - - -[ 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.
Re: Varnish 2.0.3 consuming excessive memory
Hi DES,
Darryl Dixon - Winterhouse Consulting
darryl.di...@winterhouseconsulting.com writes:
+if (req.http.Pragma ~ .*no-cache.* || req.http.Cache-Control ~
.*no-cache.*) {
+purge_url(regsub(req.url, [?].*$, .*$));
+}
+
It would be interesting to see how often this condition is true...
Shouldn't be too often in this environment - I have watched with
varnishlog and the rate is very low...
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?
I don't think so. However, your code will add an entry to the ban list
every time a request that matches the above condition is received, and
this entry will remain on the list until every object that was in the
cache before the entry was added has been requested at least once.
That sounds like a pretty good candidate then, as I can envisage that
there are possibly many items that may fit that criteria in my scenario.
However it definitely seems out of proportion to the actual cache
utilisation (only 25MB of objects in the cache, but memory growing to
multiple GB)
If you really want no-cache to purge the requested object, you should do
it in vcl_hit (set obj.ttl to 0 and pass). Otherwise, you should simply
pass directly from vcl_recv.
My understanding of using 'pass' in vcl_hit is that it causes the object
to be marked as 'hit for pass' and therefore is uncacheable from that
point onwards. In fact, pass'ing out of vcl_hit was what I used to do a
while ago, but it caused that exact behaviour (items would no longer be
cached by varnish) so I swapped it for purge_url...
regards,
Darryl Dixon
Winterhouse Consulting Ltd
http://www.winterhouseconsulting.com
___
varnish-misc mailing list
varnish-misc@projects.linpro.no
http://projects.linpro.no/mailman/listinfo/varnish-misc
Re: Varnish 2.0.3 consuming excessive memory
hi darryl i had a simlar problem (varnish child process consuming lots of memory) a week ago (see the thread make varnish don't start a subprocess) the solution for my problem seems to be to use a high-enough cache-size: starting varnish with -s file,/tmp/storage,300M will make the child process use *about* 800M RAM (the RES column in top) after some hours. after that i needed to restart varnish to free some ram for my webserver. starting with a bigger cache -s file,/tmp/storage,600M makes it using about 500M RAM (the RES column in top after 5 days of uptime) and happily coexist with zope ;-) maybe this helps you too. Hi Harald, That is a very interesting observation - I will give it a try. regards, Darryl Dixon Winterhouse Consulting Ltd http://www.winterhouseconsulting.com ___ varnish-misc mailing list varnish-misc@projects.linpro.no http://projects.linpro.no/mailman/listinfo/varnish-misc
Varnish 2.0.3 consuming excessive memory
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? regards, Darryl Dixon Winterhouse Consulting Ltd http://www.winterhouseconsulting.com ___ varnish-misc mailing list varnish-misc@projects.linpro.no http://projects.linpro.no/mailman/listinfo/varnish-misc
Re: Varnish 2.0.3 consuming excessive memory
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
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?
regards,
Darryl Dixon
Winterhouse Consulting Ltd
http://www.winterhouseconsulting.com
___
varnish-misc mailing list
varnish-misc@projects.linpro.no
http://projects.linpro.no/mailman/listinfo/varnish-misc
___
varnish-misc mailing list
varnish-misc@projects.linpro.no
http://projects.linpro.no/mailman/listinfo/varnish-misc
Re: Varnish 2.0.3 consuming excessive memory
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 RSSAnon Locked Mode Mapping 0040 312 - - - r-x-- varnishd 0064d000 8 - - - rw--- varnishd 0064f000 68 - - - rw---[ anon ] 4000 4 - - - -[ anon ] 40001000 10240 - - - rw---[ anon ] [...snip...] 2aaab090 262144 - - - rw-s- storage.cache 2aaac090 28 - - - r-x-- vcl.1P9zoqAU.so 2aaac09070002048 - - - - vcl.1P9zoqAU.so 2aaac0b07000 8 - - - rw--- vcl.1P9zoqAU.so 2aaac0c02056 - - - rw---[ anon ] 2aaac0f02052 - - - rw---[ anon ] 2aaac120 233476 - - - rw---[ anon ] 2aaacf70 2403328 - - - rw---[ anon ] 7fff4b619000 84 - - - rw---[ stack ] ff608192 - - - -[ anon ] -- -- -- -- total kB 3187344 - - - -- ...And in the time it's taken me to compose this mail it's grown by another 20MB: -- 2aaacf70 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 RSSAnon Locked Mode Mapping 0040 312 - - - r-x-- varnishd 0064d000 8 - - - rw--- varnishd 0064f000 68 - - - rw---[ anon ] 4000 4 - - - -[ anon ] 40001000 10240 - - - rw---[ anon ] [...snip...] 2aaab090 2097152 - - - rw-s- storage.cache 2aab3090 28 - - - r-x-- vcl.1P9zoqAU.so 2aab309070002044 - - - - vcl.1P9zoqAU.so 2aab30b06000 8 - - - rw--- vcl.1P9zoqAU.so 2aab30c02056 - - - rw---[ anon ] 2aab30f02056 - - - rw---[ anon ] 2aab3120 41984 - - - rw---[ anon ] 7fffae8f2000 88 - - - rw---[ stack ] ff608192 - - - -[ 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 RSSAnon Locked Mode Mapping 0040 312 - - - r-x-- varnishd 0064d000 8 - - - rw--- varnishd
