[Varnish 3] strange memory consumption after upgrade 3.0.2 -> 3.0.5
Denis Zhdanov
denis.zhdanov at gmail.com
Sat Oct 25 09:51:21 CEST 2014
Hi All,
We are trying to upgrade our varnish from pretty old 3.0.2 to 3.0.5 (3.0.6
was just released, we'll try it too, but now we are working with 3.0.5)
We are using only RAM storage, and before upgrade it consume about 90G
after 8 hours and stay like that. But it seems there's some leak in 3.0.6 -
it doesn't stop in RAM consuming until its ran out. It's not fast process -
can took a week, but after that it starts swapping and we are forced to
restart it (and lost all cache).
I tried to compare varnishstat from "bad" and "good" node but didn't find
anything strange - at least SMA.ram.g_bytes is approximately same for both
nodes.
Could someone please take a look?
Good varnishstat -1
---------------
epsvarnish_good:
client_conn 210291617 5.38 Client connections accepted
client_drop 0 0.00 Connection dropped, no sess/wrk
client_req 19264242207 493.21 Client requests received
cache_hit 17890026068 458.02 Cache hits
cache_hitpass 0 0.00 Cache hits for pass
cache_miss 1373994639 35.18 Cache misses
backend_conn 13241605 0.34 Backend conn. success
backend_unhealthy 926862 0.02 Backend conn. not attempted
backend_busy 0 0.00 Backend conn. too many
backend_fail 47 0.00 Backend conn. failures
backend_reuse 1359807120 34.81 Backend conn. reuses
backend_toolate 13870 0.00 Backend conn. was closed
backend_recycle 1359883733 34.82 Backend conn. recycles
backend_retry 44845 0.00 Backend conn. retry
fetch_head 0 0.00 Fetch head
fetch_length 1373044190 35.15 Fetch with Length
fetch_chunked 950 0.00 Fetch chunked
fetch_eof 0 0.00 Fetch EOF
fetch_bad 0 0.00 Fetch had bad headers
fetch_close 0 0.00 Fetch wanted close
fetch_oldhttp 0 0.00 Fetch pre HTTP/1.1 closed
fetch_zero 0 0.00 Fetch zero len
fetch_failed 100547 0.00 Fetch failed
fetch_1xx 0 0.00 Fetch no body (1xx)
fetch_204 0 0.00 Fetch no body (204)
fetch_304 0 0.00 Fetch no body (304)
n_sess_mem 3722 . N struct sess_mem
n_sess 1870 . N struct sess
n_object 4007618 . N struct object
n_vampireobject 0 . N unresurrected objects
n_objectcore 4009072 . N struct objectcore
n_objecthead 4023957 . N struct objecthead
n_waitinglist 6689775 . N struct waitinglist
n_vbc 20 . N struct vbc
n_wrk 1600 . N worker threads
n_wrk_create 1617 0.00 N worker threads created
n_wrk_failed 0 0.00 N worker threads not created
n_wrk_max 0 0.00 N worker threads limited
n_wrk_lqueue 0 0.00 work request queue length
n_wrk_queued 1703 0.00 N queued work requests
n_wrk_drop 0 0.00 N dropped work requests
n_backend 3 . N backends
n_expired 25190657 . N expired objects
n_lru_nuked 1343746322 . N LRU nuked objects
n_lru_moved 16549646438 . N LRU moved objects
losthdr 1771 0.00 HTTP header overflows
n_objsendfile 0 0.00 Objects sent with sendfile
n_objwrite 19157759781 490.48 Objects sent with write
n_objoverflow 0 0.00 Objects overflowing workspace
s_sess 210297216 5.38 Total Sessions
s_req 19264242207 493.21 Total Requests
s_pipe 0 0.00 Total pipe
s_pass 0 0.00 Total pass
s_fetch 1372944593 35.15 Total fetch
s_hdrbytes 7493165988804 191841.77 Total header bytes
s_bodybytes 230757381423391 5907903.79 Total body bytes
sess_closed 7877791 0.20 Session Closed
sess_pipeline 0 0.00 Session Pipeline
sess_readahead 0 0.00 Session Read Ahead
sess_linger 19261784636 493.14 Session Linger
sess_herd 12270879099 314.16 Session herd
shm_records 796058319688 20380.87 SHM records
shm_writes 34949444335 894.78 SHM writes
shm_flushes 3 0.00 SHM flushes due to overflow
shm_cont 213814789 5.47 SHM MTX contention
shm_cycles 343350 0.01 SHM cycles through buffer
sms_nreq 1271021 0.03 SMS allocator requests
sms_nobj 0 . SMS outstanding allocations
sms_nbytes 0 . SMS outstanding bytes
sms_balloc 578078958 . SMS bytes allocated
sms_bfree 578078958 . SMS bytes freed
backend_req 1373106504 35.15 Backend requests made
n_vcl 8 0.00 N vcl total
n_vcl_avail 8 0.00 N vcl available
n_vcl_discard 0 0.00 N vcl discarded
n_ban 1 . N total active bans
n_ban_add 1 0.00 N new bans added
n_ban_retire 0 0.00 N old bans deleted
n_ban_obj_test 0 0.00 N objects tested
n_ban_re_test 0 0.00 N regexps tested against
n_ban_dups 0 0.00 N duplicate bans removed
hcb_nolock 19230468606 492.34 HCB Lookups without lock
hcb_lock 1371994951 35.13 HCB Lookups with lock
hcb_insert 1371991264 35.13 HCB Inserts
esi_errors 0 0.00 ESI parse errors (unlock)
esi_warnings 0 0.00 ESI parse warnings (unlock)
accept_fail 0 0.00 Accept failures
client_drop_late 0 0.00 Connection dropped late
uptime 39059096 1.00 Client uptime
dir_dns_lookups 0 0.00 DNS director lookups
dir_dns_failed 0 0.00 DNS director failed lookups
dir_dns_hit 0 0.00 DNS director cached lookups hit
dir_dns_cache_full 0 0.00 DNS director full dnscache
vmods 1 . Loaded VMODs
n_gzip 7 0.00 Gzip operations
n_gunzip 0 0.00 Gunzip operations
VBE.autojournaal(10.32.230.188,,8484).vcls 5 . VCL
references
VBE.autojournaal(10.32.230.188,,8484).happy18446744073709551615 .
Happy health probes
VBE.beslist(10.32.230.188,,8484).vcls 1 . VCL
references
VBE.beslist(10.32.230.188,,8484).happy 18446744073709551615 .
Happy health probes
LCK.sms.creat 1 0.00
Created locks
LCK.sms.destroy 0 0.00
Destroyed locks
LCK.sms.locks 3813063 0.10 Lock
Operations
LCK.sms.colls 0 0.00
Collisions
LCK.smp.creat 0 0.00
Created locks
LCK.smp.destroy 0 0.00
Destroyed locks
LCK.smp.locks 0 0.00 Lock
Operations
LCK.smp.colls 0 0.00
Collisions
LCK.sma.creat 2 0.00
Created locks
LCK.sma.destroy 0 0.00
Destroyed locks
LCK.sma.locks 6898140689 176.61 Lock
Operations
LCK.sma.colls 0 0.00
Collisions
LCK.smf.creat 0 0.00
Created locks
LCK.smf.destroy 0 0.00
Destroyed locks
LCK.smf.locks 0 0.00 Lock
Operations
LCK.smf.colls 0 0.00
Collisions
LCK.hsl.creat 0 0.00
Created locks
LCK.hsl.destroy 0 0.00
Destroyed locks
LCK.hsl.locks 0 0.00 Lock
Operations
LCK.hsl.colls 0 0.00
Collisions
LCK.hcb.creat 1 0.00
Created locks
LCK.hcb.destroy 0 0.00
Destroyed locks
LCK.hcb.locks 2740196312 70.16 Lock
Operations
LCK.hcb.colls 0 0.00
Collisions
LCK.hcl.creat 0 0.00
Created locks
LCK.hcl.destroy 0 0.00
Destroyed locks
LCK.hcl.locks 0 0.00 Lock
Operations
LCK.hcl.colls 0 0.00
Collisions
LCK.vcl.creat 1 0.00
Created locks
LCK.vcl.destroy 0 0.00
Destroyed locks
LCK.vcl.locks 16514901 0.42 Lock
Operations
LCK.vcl.colls 0 0.00
Collisions
LCK.stat.creat 1 0.00
Created locks
LCK.stat.destroy 0 0.00
Destroyed locks
LCK.stat.locks 3722 0.00 Lock
Operations
LCK.stat.colls 0 0.00
Collisions
LCK.sessmem.creat 1 0.00
Created locks
LCK.sessmem.destroy 0 0.00
Destroyed locks
LCK.sessmem.locks 210376778 5.39 Lock
Operations
LCK.sessmem.colls 0 0.00
Collisions
LCK.wstat.creat 1 0.00
Created locks
LCK.wstat.destroy 0 0.00
Destroyed locks
LCK.wstat.locks 154004420 3.94 Lock
Operations
LCK.wstat.colls 0 0.00
Collisions
LCK.herder.creat 1 0.00
Created locks
LCK.herder.destroy 0 0.00
Destroyed locks
LCK.herder.locks 31 0.00 Lock
Operations
LCK.herder.colls 0 0.00
Collisions
LCK.wq.creat 16 0.00
Created locks
LCK.wq.destroy 0 0.00
Destroyed locks
LCK.wq.locks 25196944400 645.10 Lock
Operations
LCK.wq.colls 0 0.00
Collisions
LCK.objhdr.creat 1371962780 35.13
Created locks
LCK.objhdr.destroy 1367969515 35.02
Destroyed locks
LCK.objhdr.locks 79782749795 2042.62 Lock
Operations
LCK.objhdr.colls 0 0.00
Collisions
LCK.exp.creat 1 0.00
Created locks
LCK.exp.destroy 0 0.00
Destroyed locks
LCK.exp.locks 2780936064 71.20 Lock
Operations
LCK.exp.colls 0 0.00
Collisions
LCK.lru.creat 2 0.00
Created locks
LCK.lru.destroy 0 0.00
Destroyed locks
LCK.lru.locks 2716690775 69.55 Lock
Operations
LCK.lru.colls 0 0.00
Collisions
LCK.cli.creat 1 0.00
Created locks
LCK.cli.destroy 0 0.00
Destroyed locks
LCK.cli.locks 2227237 0.06 Lock
Operations
LCK.cli.colls 0 0.00
Collisions
LCK.ban.creat 1 0.00
Created locks
LCK.ban.destroy 0 0.00
Destroyed locks
LCK.ban.locks 2781138078 71.20 Lock
Operations
LCK.ban.colls 0 0.00
Collisions
LCK.vbp.creat 1 0.00
Created locks
LCK.vbp.destroy 0 0.00
Destroyed locks
LCK.vbp.locks 9013627 0.23 Lock
Operations
LCK.vbp.colls 0 0.00
Collisions
LCK.vbe.creat 1 0.00
Created locks
LCK.vbe.destroy 0 0.00
Destroyed locks
LCK.vbe.locks 26485466 0.68 Lock
Operations
LCK.vbe.colls 0 0.00
Collisions
LCK.backend.creat 3 0.00
Created locks
LCK.backend.destroy 0 0.00
Destroyed locks
LCK.backend.locks 2773680373 71.01 Lock
Operations
LCK.backend.colls 0 0.00
Collisions
SMA.ram.c_req 4109962205 105.22
Allocator requests
SMA.ram.c_fail 52455807295423 1342985.70
Allocator failures
SMA.ram.c_bytes 27203969692807 696482.32
Bytes allocated
SMA.ram.c_freed 27128807778988 694558.00
Bytes freed
SMA.ram.g_alloc 8016209 .
Allocations outstanding
SMA.ram.g_bytes 75161913819 . Bytes
outstanding
SMA.ram.g_space 13861 . Bytes
available
SMA.Transient.c_req 47750773 1.22
Allocator requests
SMA.Transient.c_fail 0 0.00
Allocator failures
SMA.Transient.c_bytes 58471006951 1496.99 Bytes
allocated
SMA.Transient.c_freed 58470979290 1496.99 Bytes
freed
SMA.Transient.g_alloc 22 .
Allocations outstanding
SMA.Transient.g_bytes 27661 . Bytes
outstanding
SMA.Transient.g_space 0 . Bytes
available
VBE.proxy(10.x.x.x,,80).vcls 8 . VCL references
VBE.proxy(10.x.x.x,,80).happy 18446744073709551615 . Happy
health probes
---------------
Bad varnishstat -1
---------------
epsvarnish_bad:
client_conn 2661600 6.43 Client connections accepted
client_drop 0 0.00 Connection dropped, no sess/wrk
client_req 238438255 575.65 Client requests received
cache_hit 213261383 514.87 Cache hits
cache_hitpass 0 0.00 Cache hits for pass
cache_miss 25173891 60.78 Cache misses
backend_conn 397844 0.96 Backend conn. success
backend_unhealthy 18139 0.04 Backend conn. not attempted
backend_busy 0 0.00 Backend conn. too many
backend_fail 2675 0.01 Backend conn. failures
backend_reuse 24825052 59.93 Backend conn. reuses
backend_toolate 45 0.00 Backend conn. was closed
backend_recycle 24825811 59.94 Backend conn. recycles
backend_retry 70506 0.17 Backend conn. retry
fetch_head 0 0.00 Fetch head
fetch_length 25137933 60.69 Fetch with Length
fetch_chunked 10 0.00 Fetch chunked
fetch_eof 0 0.00 Fetch EOF
fetch_bad 0 0.00 Fetch had bad headers
fetch_close 0 0.00 Fetch wanted close
fetch_oldhttp 0 0.00 Fetch pre HTTP/1.1 closed
fetch_zero 0 0.00 Fetch zero len
fetch_failed 530 0.00 Fetch failed
fetch_1xx 0 0.00 Fetch no body (1xx)
fetch_204 0 0.00 Fetch no body (204)
fetch_304 0 0.00 Fetch no body (304)
n_sess_mem 4732 . N struct sess_mem
n_sess 148 . N struct sess
n_object 4003646 . N struct object
n_vampireobject 0 . N unresurrected objects
n_objectcore 4004774 . N struct objectcore
n_objecthead 4015924 . N struct objecthead
n_waitinglist 1588 . N struct waitinglist
n_vbc 22 . N struct vbc
n_wrk 1600 . N worker threads
n_wrk_create 3068 0.01 N worker threads created
n_wrk_failed 0 0.00 N worker threads not created
n_wrk_max 0 0.00 N worker threads limited
n_wrk_lqueue 0 0.00 work request queue length
n_wrk_queued 13255 0.03 N queued work requests
n_wrk_drop 0 0.00 N dropped work requests
n_backend 3 . N backends
n_expired 263264 . N expired objects
n_lru_nuked 20870512 . N LRU nuked objects
n_lru_moved 200584889 . N LRU moved objects
losthdr 8 0.00 HTTP header overflows
n_objsendfile 0 0.00 Objects sent with sendfile
n_objwrite 236130810 570.08 Objects sent with write
n_objoverflow 0 0.00 Objects overflowing workspace
s_sess 2661694 6.43 Total Sessions
s_req 238438255 575.65 Total Requests
s_pipe 0 0.00 Total pipe
s_pass 0 0.00 Total pass
s_fetch 25137413 60.69 Total fetch
s_hdrbytes 117632270881 283995.98 Total header bytes
s_bodybytes 2917193607304 7042890.96 Total body bytes
sess_closed 169195 0.41 Session Closed
sess_pipeline 0 0.00 Session Pipeline
sess_readahead 0 0.00 Session Read Ahead
sess_linger 238353273 575.45 Session Linger
sess_herd 148971811 359.66 Session herd
shm_records 10788946827 26047.42 SHM records
shm_writes 446371290 1077.66 SHM writes
shm_flushes 0 0.00 SHM flushes due to overflow
shm_cont 2328506 5.62 SHM MTX contention
shm_cycles 4750 0.01 SHM cycles through buffer
sms_nreq 39446 0.10 SMS allocator requests
sms_nobj 0 . SMS outstanding allocations
sms_nbytes 0 . SMS outstanding bytes
sms_balloc 18106011 . SMS bytes allocated
sms_bfree 18106011 . SMS bytes freed
backend_req 25222980 60.90 Backend requests made
n_vcl 2 0.00 N vcl total
n_vcl_avail 2 0.00 N vcl available
n_vcl_discard 0 0.00 N vcl discarded
n_ban 1 . N total active bans
n_ban_gone 1 . N total gone bans
n_ban_add 1 0.00 N new bans added
n_ban_retire 0 0.00 N old bans deleted
n_ban_obj_test 0 0.00 N objects tested
n_ban_re_test 0 0.00 N regexps tested against
n_ban_dups 0 0.00 N duplicate bans removed
hcb_nolock 238293148 575.30 HCB Lookups without lock
hcb_lock 25165922 60.76 HCB Lookups with lock
hcb_insert 25165889 60.76 HCB Inserts
esi_errors 0 0.00 ESI parse errors (unlock)
esi_warnings 0 0.00 ESI parse warnings (unlock)
accept_fail 0 0.00 Accept failures
client_drop_late 0 0.00 Connection dropped late
uptime 414204 1.00 Client uptime
dir_dns_lookups 0 0.00 DNS director lookups
dir_dns_failed 0 0.00 DNS director failed lookups
dir_dns_hit 0 0.00 DNS director cached lookups hit
dir_dns_cache_full 0 0.00 DNS director full dnscache
vmods 1 . Loaded VMODs
n_gzip 0 0.00 Gzip operations
n_gunzip 0 0.00 Gunzip operations
sess_pipe_overflow 0 . Dropped sessions due to session
pipe overflow
LCK.sms.creat 1 0.00 Created locks
LCK.sms.destroy 0 0.00 Destroyed locks
LCK.sms.locks 118338 0.29 Lock Operations
LCK.sms.colls 0 0.00 Collisions
LCK.smp.creat 0 0.00 Created locks
LCK.smp.destroy 0 0.00 Destroyed locks
LCK.smp.locks 0 0.00 Lock Operations
LCK.smp.colls 0 0.00 Collisions
LCK.sma.creat 2 0.00 Created locks
LCK.sma.destroy 0 0.00 Destroyed locks
LCK.sma.locks 114658606 276.82 Lock Operations
LCK.sma.colls 0 0.00 Collisions
LCK.smf.creat 0 0.00 Created locks
LCK.smf.destroy 0 0.00 Destroyed locks
LCK.smf.locks 0 0.00 Lock Operations
LCK.smf.colls 0 0.00 Collisions
LCK.hsl.creat 0 0.00 Created locks
LCK.hsl.destroy 0 0.00 Destroyed locks
LCK.hsl.locks 0 0.00 Lock Operations
LCK.hsl.colls 0 0.00 Collisions
LCK.hcb.creat 1 0.00 Created locks
LCK.hcb.destroy 0 0.00 Destroyed locks
LCK.hcb.locks 46330459 111.85 Lock Operations
LCK.hcb.colls 0 0.00 Collisions
LCK.hcl.creat 0 0.00 Created locks
LCK.hcl.destroy 0 0.00 Destroyed locks
LCK.hcl.locks 0 0.00 Lock Operations
LCK.hcl.colls 0 0.00 Collisions
LCK.vcl.creat 1 0.00 Created locks
LCK.vcl.destroy 0 0.00 Destroyed locks
LCK.vcl.locks 175044 0.42 Lock Operations
LCK.vcl.colls 0 0.00 Collisions
LCK.stat.creat 1 0.00 Created locks
LCK.stat.destroy 0 0.00 Destroyed locks
LCK.stat.locks 2666278 6.44 Lock Operations
LCK.stat.colls 0 0.00 Collisions
LCK.sessmem.creat 1 0.00 Created locks
LCK.sessmem.destroy 0 0.00 Destroyed locks
LCK.sessmem.locks 2667059 6.44 Lock Operations
LCK.sessmem.colls 0 0.00 Collisions
LCK.wstat.creat 1 0.00 Created locks
LCK.wstat.destroy 0 0.00 Destroyed locks
LCK.wstat.locks 1316488 3.18 Lock Operations
LCK.wstat.colls 0 0.00 Collisions
LCK.herder.creat 1 0.00 Created locks
LCK.herder.destroy 0 0.00 Destroyed locks
LCK.herder.locks 11717 0.03 Lock Operations
LCK.herder.colls 0 0.00 Collisions
LCK.wq.creat 16 0.00 Created locks
LCK.wq.destroy 0 0.00 Destroyed locks
LCK.wq.locks 305048412 736.47 Lock Operations
LCK.wq.colls 0 0.00 Collisions
LCK.objhdr.creat 25167014 60.76 Created locks
LCK.objhdr.destroy 21151796 51.07 Destroyed locks
LCK.objhdr.locks 996006829 2404.63 Lock Operations
LCK.objhdr.colls 0 0.00 Collisions
LCK.exp.creat 1 0.00 Created locks
LCK.exp.destroy 0 0.00 Destroyed locks
LCK.exp.locks 46685330 112.71 Lock Operations
LCK.exp.colls 0 0.00 Collisions
LCK.lru.creat 2 0.00 Created locks
LCK.lru.destroy 0 0.00 Destroyed locks
LCK.lru.locks 46007928 111.08 Lock Operations
LCK.lru.colls 0 0.00 Collisions
LCK.cli.creat 1 0.00 Created locks
LCK.cli.destroy 0 0.00 Destroyed locks
LCK.cli.locks 88654 0.21 Lock Operations
LCK.cli.colls 0 0.00 Collisions
LCK.ban.creat 1 0.00 Created locks
LCK.ban.destroy 0 0.00 Destroyed locks
LCK.ban.locks 46686411 112.71 Lock Operations
LCK.ban.colls 0 0.00 Collisions
LCK.vbp.creat 1 0.00 Created locks
LCK.vbp.destroy 0 0.00 Destroyed locks
LCK.vbp.locks 125227 0.30 Lock Operations
LCK.vbp.colls 0 0.00 Collisions
LCK.vbe.creat 1 0.00 Created locks
LCK.vbe.destroy 0 0.00 Destroyed locks
LCK.vbe.locks 801030 1.93 Lock Operations
LCK.vbe.colls 0 0.00 Collisions
LCK.backend.creat 3 0.00 Created locks
LCK.backend.destroy 0 0.00 Destroyed locks
LCK.backend.locks 50871308 122.82 Lock Operations
LCK.backend.colls 0 0.00 Collisions
SMA.ram.c_req 71969321 173.75 Allocator requests
SMA.ram.c_fail 22016345 53.15 Allocator failures
SMA.ram.c_bytes 504148551835 1217150.37 Bytes allocated
SMA.ram.c_freed 428986641816 1035689.28 Bytes freed
SMA.ram.g_alloc 8008174 . Allocations outstanding
SMA.ram.g_bytes 75161910019 . Bytes outstanding
SMA.ram.g_space 17661 . Bytes available
SMA.Transient.c_req 368754 0.89 Allocator requests
SMA.Transient.c_fail 0 0.00 Allocator failures
SMA.Transient.c_bytes 463851431 1119.86 Bytes allocated
SMA.Transient.c_freed 463818676 1119.78 Bytes freed
SMA.Transient.g_alloc 26 . Allocations outstanding
SMA.Transient.g_bytes 32755 . Bytes outstanding
SMA.Transient.g_space 0 . Bytes available
VBE.proxy(10.x.x.x,,80).vcls 2 . VCL references
VBE.proxy(10.x.x.x,,80).happy18446744073709551615 . Happy health
probes
---------------
Command line
/usr/sbin/varnishd -P /var/run/varnishd.pid -a :80 -f
/etc/varnish/varnish.vcl -T :6082 -S /etc/varnish/secret -s ram=malloc,70G
-p thread_pool_add_delay=2 -p http_gzip_support=on -p thread_pools=16 -p
default_ttl=7200 -p thread_pool_min=100 -p thread_pool_max=4000 -p
session_linger=50 -p sess_workspace=1048576 -p shm_workspace=8192
Server is PowerEdge M610, 96G RAM, 2xXeon E5620+HT (16 cores).
Good system running on Debian Squeeze, Bad one - on Ubuntu Precise (yep, I
know, it was a bad idea to change varnish and OS in same time *sigh*)
With best regards,
Denis
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <https://www.varnish-cache.org/lists/pipermail/varnish-misc/attachments/20141025/279cff35/attachment-0001.html>
More information about the varnish-misc
mailing list