Hi Geoff,
You're right, the patch didn't make any difference. The problem was that
I was running an earlier version of the unpatched trunk which contained
the ws overflow bug, so the reason memory usage was dropping from time
to time was because one of the threads was dying.
I've installed the latest trunk and it behaved exactly like the patched
version: after about 80k requests the virtual memory size was about 2G
(I have 1G storage configured). I ran varnishstat -1 after that (attached).
So it looks like there is a memory leak in the current trunk.
On 10/03/2011 19:41, Geoff Simmons wrote:
-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA256
On 3/10/11 7:18 PM, Dmitry Panov wrote:
I have finally been able to test the patched version under some proper
load. I was using tsung (http://tsung.erlang-projects.org/). I recorded
a browser session in which I accessed a couple of pages, then tried to
replay it with tsung.
It looks like there is a memory leak in the patched version because the
virtual memory size grew at a constant pace until eventually varnishd
filled up the whole available space. I tried exactly the same scenario
with an unpatched trunk (same revision that I applied the patch to) and
it worked fine. Note there were no stale objects or conditional requests
during the test because I set ttl to a high value so it's either a hit
or a miss for an uncacheable object.
Thanks as always, Dmitry. That last part is interesting, if there are no
stale objects or conditional requests, then Varnish should behave
exactly as if the patch weren't there.
I assume you tested the most recent version of the patch (v5, attached
to the mail that you quoted)? I had fixed a memory leak in an earlier
version; but that leak only could have happened if there had been stale
objects.
Did you notice whether there were more cache misses with the patched
version? And did you by any chance run varnishstat -1 after load testing
the two versions? If so, I'd be interested if there were any noticeable
difference in stats about memory usage, such as n_object, s_hdrbytes,
s_bodybytes or the stevedore stats.
BTW, with default settings (default_keep = 0), the patched version won't
do any conditional requests, so that should be enough to get it to
behave the same as the unpatched version.
I have a rather complex setup which includes apache with mod_proxy_html
which I use to reverse proxy a real Internet web site
(www.telegraph.co.uk). If there is anything I can do to help you
diagnose the problem, please let me know.
I'll see if I can get the same effect with my own load tests, if not
I'll get in touch.
Thanks again,
Geoff
--
Dmitry Panov
client_conn 22999 48.52 Client connections accepted
client_drop 0 0.00 Connection dropped, no sess/wrk
client_req 80829 170.53 Client requests received
cache_hit 80427 169.68 Cache hits
cache_hitpass 241 0.51 Cache hits for pass
cache_miss 161 0.34 Cache misses
backend_conn 13 0.03 Backend conn. success
backend_unhealthy 0 0.00 Backend conn. not attempted
backend_busy 0 0.00 Backend conn. too many
backend_fail 0 0.00 Backend conn. failures
backend_reuse 389 0.82 Backend conn. reuses
backend_toolate 9 0.02 Backend conn. was closed
backend_recycle 401 0.85 Backend conn. recycles
backend_unused 0 0.00 Backend conn. unused
backend_retry 0 0.00 Backend conn. retry
fetch_head 0 0.00 Fetch head
fetch_length 103 0.22 Fetch with Length
fetch_chunked 299 0.63 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 0 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 805 . N struct sess_mem
n_sess 6 . N struct sess
n_object 104 . N struct object
n_vampireobject 0 . N unresurrected objects
n_objectcore 603 . N struct objectcore
n_objecthead 605 . N struct objecthead
n_waitinglist 504 . N struct waitinglist
n_vbc 3 . N struct vbc
n_wrk 500 . N worker threads
n_wrk_create 500 1.05 N worker threads created
n_wrk_failed 0 0.00 N worker threads not created
n_wrk_max 845 1.78 N worker threads limited
n_wrk_lqueue 0 0.00 work request queue length
n_wrk_queued 6572 13.86 N queued work requests
n_wrk_drop 0 0.00 N dropped work requests
n_backend 3 . N backends
n_expired 59 . N expired objects
n_lru_nuked 0 . N LRU nuked objects
n_lru_moved 13571 . N LRU moved objects
losthdr 0 0.00 HTTP header overflows
n_objsendfile 0 0.00 Objects sent with sendfile
n_objwrite 78565 165.75 Objects sent with write
n_objoverflow 0 0.00 Objects overflowing workspace
s_sess 22996 48.51 Total Sessions
s_req 80829 170.53 Total Requests
s_pipe 0 0.00 Total pipe
s_pass 241 0.51 Total pass
s_fetch 402 0.85 Total fetch
s_hdrbytes 25298690 53372.76 Total header bytes
s_bodybytes 866092594 1827199.57 Total body bytes
sess_closed 8815 18.60 Session Closed
sess_pipeline 0 0.00 Session Pipeline
sess_readahead 0 0.00 Session Read Ahead
sess_linger 80416 169.65 Session Linger
sess_herd 41740 88.06 Session herd
shm_records 2853843 6020.77 SHM records
shm_writes 193194 407.58 SHM writes
shm_flushes 0 0.00 SHM flushes due to overflow
shm_cont 21 0.04 SHM MTX contention
shm_cycles 0 0.00 SHM cycles through buffer
sms_nreq 0 0.00 SMS allocator requests
sms_nobj 0 . SMS outstanding allocations
sms_nbytes 0 . SMS outstanding bytes
sms_balloc 0 . SMS bytes allocated
sms_bfree 0 . SMS bytes freed
backend_req 402 0.85 Backend requests made
n_vcl 1 0.00 N vcl total
n_vcl_avail 1 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 80837 170.54 HCB Lookups without lock
hcb_lock 105 0.22 HCB Lookups with lock
hcb_insert 105 0.22 HCB Inserts
esi_parse 0 0.00 Objects ESI parsed (unlock)
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 474 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 0 . Loaded VMODs
n_gzip 0 0.00 Gzip operations
n_gunzip 36184 76.34 Gunzip operations
LCK.sms.creat 1 0.00 Created locks
LCK.sms.destroy 0 0.00 Destroyed locks
LCK.sms.locks 0 0.00 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 1 0.00 Created locks
LCK.sma.destroy 0 0.00 Destroyed locks
LCK.sma.locks 1245 2.63 Lock Operations
LCK.sma.colls 0 0.00 Collisions
LCK.smf.creat 1 0.00 Created locks
LCK.smf.destroy 0 0.00 Destroyed locks
LCK.smf.locks 477 1.01 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 111 0.23 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 506 1.07 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 805 1.70 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 24884 52.50 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 951 2.01 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 6443 13.59 Lock Operations
LCK.herder.colls 0 0.00 Collisions
LCK.wq.creat 2 0.00 Created locks
LCK.wq.destroy 0 0.00 Destroyed locks
LCK.wq.locks 102572 216.40 Lock Operations
LCK.wq.colls 0 0.00 Collisions
LCK.objhdr.creat 605 1.28 Created locks
LCK.objhdr.destroy 0 0.00 Destroyed locks
LCK.objhdr.locks 323444 682.37 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 693 1.46 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 161 0.34 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 171 0.36 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 693 1.46 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 0 0.00 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 23 0.05 Lock Operations
LCK.vbe.colls 0 0.00 Collisions
LCK.backend.creat 3 0.01 Created locks
LCK.backend.destroy 0 0.00 Destroyed locks
LCK.backend.locks 896 1.89 Lock Operations
LCK.backend.colls 0 0.00 Collisions
SMF.s0.nreq 302 0.64 Allocator requests
SMF.s0.nobj 207 . Outstanding allocations
SMF.s0.nbytes 0 . Outstanding bytes
SMF.s0.balloc 2023424 . Bytes allocated
SMF.s0.bfree 1071718400 . Bytes free
SMF.s0.n_smf 218 . N struct smf
SMF.s0.n_smf_frag 8 . N small free smf
SMF.s0.n_smf_large 3 . N large free smf
SMA.Transient.nreq 498 1.05 Allocator requests
SMA.Transient.nobj 0 . Outstanding allocations
SMA.Transient.nbytes 0 . Outstanding bytes
SMA.Transient.balloc 32812116 . Bytes allocated
SMA.Transient.bfree 32812116 . Bytes free
VBE.default(127.0.0.1,,80).vcls 18446744073709551309 . VCL references
VBE.default(127.0.0.1,,80).happy 0 . Happy health probes
VBE.telegraph(10.83.102.2,,80).vcls 1 . VCL references
VBE.telegraph(10.83.102.2,,80).happy 0 . Happy health
probes
VBE.i_telegraph(92.123.68.122,,80).vcls 18446744073709551514 . VCL
references
VBE.i_telegraph(92.123.68.122,,80).happy 0 . Happy health
probes
_______________________________________________
varnish-dev mailing list
[email protected]
http://www.varnish-cache.org/lists/mailman/listinfo/varnish-dev
