suspicious memory usage with 3.0.5
Lucas Luitjes
lucas at silk.co
Mon Dec 21 15:44:41 CET 2015
Hi,
We're handling only 2-8 req/s and are using file based storage. Yet
somehow varnish is using 1-2GB memory. RSS, not VM. I looked at the
usual suspects, but the Transient storage is barely used, and there are
only 33000 objects in cache so it can't be the object overhead either.
I've read through two years worth on this list but wasn't able to find
other possible causes.
Can anybody point me in the right direction?
I'm starting varnish with the following options:
DAEMON_OPTS="-a :80 \
-T localhost:6082 \
-f /etc/varnish/default.vcl \
-S /etc/varnish/secret \
-p sess_timeout=30s \
-p shm_reclen=2048 \
-s file,/mnt/varnish-storage/varnish.bin,15000m\
-w 100,1000,120"
ps output:
USER PID %CPU %MEM VSZ RSS TTY STAT START TIME COMMAND
root 19382 0.0 0.1 126700 5200 ? Ss Dec13 0:15
/usr/sbin/varnishd -P /var/run/varnishd.pid -a :80 -T localhost:6082 -f
/etc/varnish/default.vcl -S /etc/varnish/secret -p sess_timeout=30s -p
shm_reclen=2048 -s
nobody 19386 0.4 31.5 4081716 1215100 ? Sl Dec13 46:45
/usr/sbin/varnishd -P /var/run/varnishd.pid -a :80 -T localhost:6082 -f
/etc/varnish/default.vcl -S /etc/varnish/secret -p sess_timeout=30s -p
shm_reclen=2048 -s
Param.show:
varnish> param.show
200
acceptor_sleep_decay 0.900000 []
acceptor_sleep_incr 0.001000 [s]
acceptor_sleep_max 0.050000 [s]
auto_restart on [bool]
ban_dups on [bool]
ban_lurker_sleep 0.010000 [s]
between_bytes_timeout 60.000000 [s]
cc_command "exec gcc -std=gnu99 -g -O2
-fstack-protector --param=ssp-buffer-size=4 -Wformat
-Werror=format-security -pthread -fpic -shared -Wl,-x -o %o %s"
cli_buffer 8192 [bytes]
cli_timeout 10 [seconds]
clock_skew 10 [s]
connect_timeout 0.700000 [s]
critbit_cooloff 180.000000 [s]
default_grace 10.000000 [seconds]
default_keep 0.000000 [seconds]
default_ttl 120.000000 [seconds]
diag_bitmap 0x0 [bitmap]
esi_syntax 0 [bitmap]
expiry_sleep 1.000000 [seconds]
fetch_chunksize 128 [kilobytes]
fetch_maxchunksize 262144 [kilobytes]
first_byte_timeout 60.000000 [s]
group nogroup (65534)
gzip_level 6 []
gzip_memlevel 8 []
gzip_stack_buffer 32768 [Bytes]
gzip_tmp_space 0 []
gzip_window 15 []
http_gzip_support on [bool]
http_max_hdr 64 [header lines]
http_range_support on [bool]
http_req_hdr_len 8192 [bytes]
http_req_size 32768 [bytes]
http_resp_hdr_len 8192 [bytes]
http_resp_size 32768 [bytes]
idle_send_timeout 60 [seconds]
listen_address :80
listen_depth 1024 [connections]
log_hashstring on [bool]
log_local_address off [bool]
lru_interval 2 [seconds]
max_esi_depth 5 [levels]
max_restarts 4 [restarts]
nuke_limit 50 [allocations]
pcre_match_limit 10000 []
pcre_match_limit_recursion 10000 []
ping_interval 3 [seconds]
pipe_timeout 60 [seconds]
prefer_ipv6 off [bool]
queue_max 100 [%]
rush_exponent 3 [requests per request]
saintmode_threshold 10 [objects]
send_timeout 600 [seconds]
sess_timeout 30 [seconds]
sess_workspace 65536 [bytes]
session_linger 50 [ms]
session_max 100000 [sessions]
shm_reclen 2048 [bytes]
shm_workspace 8192 [bytes]
shortlived 10.000000 [s]
syslog_cli_traffic on [bool]
thread_pool_add_delay 2 [milliseconds]
thread_pool_add_threshold 2 [requests]
thread_pool_fail_delay 200 [milliseconds]
thread_pool_max 1000 [threads]
thread_pool_min 100 [threads]
thread_pool_purge_delay 1000 [milliseconds]
thread_pool_stack unlimited [bytes]
thread_pool_timeout 120 [seconds]
thread_pool_workspace 65536 [bytes]
thread_pools 2 [pools]
thread_stats_rate 10 [requests]
user nobody (65534)
vcc_err_unref on [bool]
vcl_dir /etc/varnish
vcl_trace off [bool]
vmod_dir /usr/lib/x86_64-linux-gnu/varnish/vmods
waiter default (epoll, poll)
Varnishstat:
varnishstat -1
client_conn 1137599 1.63 Client connections accepted
client_drop 0 0.00 Connection dropped, no sess/wrk
client_req 2032210 2.91 Client requests received
cache_hit 341943 0.49 Cache hits
cache_hitpass 1842 0.00 Cache hits for pass
cache_miss 708115 1.01 Cache misses
backend_conn 89175 0.13 Backend conn. success
backend_unhealthy 0 0.00 Backend conn. not attempted
backend_busy 0 0.00 Backend conn. too many
backend_fail 560 0.00 Backend conn. failures
backend_reuse 1578521 2.26 Backend conn. reuses
backend_toolate 13907 0.02 Backend conn. was closed
backend_recycle 1592791 2.28 Backend conn. recycles
backend_retry 3123 0.00 Backend conn. retry
fetch_head 11776 0.02 Fetch head
fetch_length 198636 0.28 Fetch with Length
fetch_chunked 1387593 1.99 Fetch chunked
fetch_eof 0 0.00 Fetch EOF
fetch_bad 0 0.00 Fetch had bad headers
fetch_close 371 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 23 0.00 Fetch failed
fetch_1xx 0 0.00 Fetch no body (1xx)
fetch_204 0 0.00 Fetch no body (204)
fetch_304 854 0.00 Fetch no body (304)
n_sess_mem 199 . N struct sess_mem
n_sess 22 . N struct sess
n_object 32945 . N struct object
n_vampireobject 0 . N unresurrected objects
n_objectcore 33006 . N struct objectcore
n_objecthead 33434 . N struct objecthead
n_waitinglist 175 . N struct waitinglist
n_vbc 10 . N struct vbc
n_wrk 200 . N worker threads
n_wrk_create 200 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 2 0.00 N queued work requests
n_wrk_drop 0 0.00 N dropped work requests
n_backend 4 . N backends
n_expired 274186 . N expired objects
n_lru_nuked 394697 . N LRU nuked objects
n_lru_moved 286567 . N LRU moved objects
losthdr 8 0.00 HTTP header overflows
n_objsendfile 0 0.00 Objects sent with sendfile
n_objwrite 1993358 2.86 Objects sent with write
n_objoverflow 0 0.00 Objects overflowing workspace
s_sess 1137600 1.63 Total Sessions
s_req 2032210 2.91 Total Requests
s_pipe 62579 0.09 Total pipe
s_pass 894827 1.28 Total pass
s_fetch 1594496 2.28 Total fetch
s_hdrbytes 944136821 1352.28 Total header bytes
s_bodybytes 50610526058 72489.02 Total body bytes
sess_closed 230365 0.33 Session Closed
sess_pipeline 106 0.00 Session Pipeline
sess_readahead 0 0.00 Session Read Ahead
sess_linger 1857635 2.66 Session Linger
sess_herd 1831395 2.62 Session herd
shm_records 179189892 256.65 SHM records
shm_writes 13094383 18.75 SHM writes
shm_flushes 4218 0.01 SHM flushes due to overflow
shm_cont 12594 0.02 SHM MTX contention
shm_cycles 104 0.00 SHM cycles through buffer
sms_nreq 11871 0.02 SMS allocator requests
sms_nobj 0 . SMS outstanding allocations
sms_nbytes 0 . SMS outstanding bytes
sms_balloc 10070143 . SMS bytes allocated
sms_bfree 10070143 . SMS bytes freed
backend_req 1601778 2.29 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 45 . N total active bans
n_ban_gone 42 . N total gone bans
n_ban_add 173359 0.25 N new bans added
n_ban_retire 173314 0.25 N old bans deleted
n_ban_obj_test 65906808 94.40 N objects tested
n_ban_re_test 233394372 334.29 N regexps tested against
n_ban_dups 168535 0.24 N duplicate bans removed
hcb_nolock 1051594 1.51 HCB Lookups without lock
hcb_lock 705667 1.01 HCB Lookups with lock
hcb_insert 705663 1.01 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 698182 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 5 . Loaded VMODs
n_gzip 0 0.00 Gzip operations
n_gunzip 666967 0.96 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 35613 0.05 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 4808562 6.89 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 3799704 5.44 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 1382264 1.98 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 2387 0.00 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 1137777 1.63 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 1146538 1.64 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 713721 1.02 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 1 0.00 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 5522531 7.91 Lock Operations
LCK.wq.colls 0 0.00 Collisions
LCK.objhdr.creat 705475 1.01 Created locks
LCK.objhdr.destroy 672290 0.96 Destroyed locks
LCK.objhdr.locks 73461950 105.22 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 2312896 3.31 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 1340625 1.92 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 232608 0.33 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 135656520 194.30 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 179544 0.26 Lock Operations
LCK.vbe.colls 0 0.00 Collisions
LCK.backend.creat 4 0.00 Created locks
LCK.backend.destroy 0 0.00 Destroyed locks
LCK.backend.locks 3454891 4.95 Lock Operations
LCK.backend.colls 0 0.00 Collisions
SMF.s0.c_req 1797552 2.57 Allocator requests
SMF.s0.c_fail 395043 0.57 Allocator failures
SMF.s0.c_bytes 95012720640 136085.89 Bytes allocated
SMF.s0.c_freed 94071521280 134737.82 Bytes freed
SMF.s0.g_alloc 67056 . Allocations outstanding
SMF.s0.g_bytes 941199360 . Bytes outstanding
SMF.s0.g_space 840527872 . Bytes available
SMF.s0.g_smf 76469 . N struct smf
SMF.s0.g_smf_frag 9402 . N small free smf
SMF.s0.g_smf_large 11 . N large free smf
SMA.Transient.c_req 1954222 2.80 Allocator requests
SMA.Transient.c_fail 0 0.00 Allocator failures
SMA.Transient.c_bytes 135146176063 193568.69 Bytes allocated
SMA.Transient.c_freed 135146173687 193568.69 Bytes freed
SMA.Transient.g_alloc 2 . Allocations outstanding
SMA.Transient.g_bytes 2376 . Bytes outstanding
SMA.Transient.g_space 0 . Bytes available
VBE.prerender(10.0.0.194,,12000).vcls 1 . VCL references
VBE.prerender(10.0.0.194,,12000).happy 0 . Happy health probes
VBE.haproxy(127.0.0.1,,8080).vcls 1 . VCL references
VBE.haproxy(127.0.0.1,,8080).happy 0 . Happy health probes
VBE.tuna(127.0.0.1,,5555).vcls 1 . VCL references
VBE.tuna(127.0.0.1,,5555).happy 0 . Happy health probes
VBE.apache(127.0.0.1,,81).vcls 1 . VCL references
VBE.apache(127.0.0.1,,81).happy 0 . Happy health probes
Thanks!
Lucas Luitjes
More information about the varnish-misc
mailing list