Re: Varnish 2.0.3 consuming excessive memory

2009-04-15 Thread 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.


 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

2009-04-14 Thread Tollef Fog Heen
]] 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

2009-04-14 Thread 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.


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

2009-04-08 Thread Dag-Erling Smørgrav
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

2009-04-08 Thread Harald Friessnegger
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

2009-04-08 Thread Darryl Dixon - Winterhouse Consulting
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

2009-04-08 Thread Darryl Dixon - Winterhouse Consulting
 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

2009-04-07 Thread Darryl Dixon - Winterhouse Consulting
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

2009-04-07 Thread Michael S. Fischer
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

2009-04-07 Thread Darryl Dixon - Winterhouse Consulting
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