Varnish - high session_linger and session herd
Barry Conroy
barrycie at aol.com
Wed May 23 13:18:13 CEST 2012
Hi all,
Ive been testing Varnish over the past while and have a few questions
with which i hope you can help.
We have deployed Varnish 3.0.2 in front of our XML api.
During my load testing Ive noticed that the session_linger and
session_herd stats are quite high. Does this signal an issue?
Also, during my load testing Im getting an error for 0.04% of requests
to Varnish - "readResponse: java.net.SocketException: Connection reset
". Has anyone seen this before? Are these connections getting closed on
the Varnish side?
I had been using the default setting for session_linger but changed it
to 0. Do I need session linger considering I am not caching a web page
but am instead caching XML api responses?
I was surprised how little memory Varnish is using to cache its objects
- this is reflect in the line
SMA.s0.g_bytes 2109235 . Bytes outstanding
The following are the output from varnishstat -1 and also the
param.show. The VCL in play is very simple and passes through 1 request
type and caches everything else.
Thanks for you help in advance,
Barry
client_conn 5990408 14.10 Client connections accepted
client_drop 0 0.00 Connection dropped, no sess/wrk
client_req 2351555655 5534.53 Client requests received
cache_hit 2346417108 5522.44 Cache hits
cache_hitpass 0 0.00 Cache hits for pass
cache_miss 4836412 11.38 Cache misses
backend_conn 11271 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 2 0.00 Backend conn. failures
backend_reuse 5127357 12.07 Backend conn. reuses
backend_toolate 1044 0.00 Backend conn. was closed
backend_recycle 5128407 12.07 Backend conn. recycles
backend_retry 99 0.00 Backend conn. retry
fetch_head 295036 0.69 Fetch head
fetch_length 4836477 11.38 Fetch with Length
fetch_chunked 7012 0.02 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 1251 . N struct sess_mem
n_sess 789 . N struct sess
n_object 453 . N struct object
n_vampireobject 0 . N unresurrected objects
n_objectcore 627 . N struct objectcore
n_objecthead 1859 . N struct objecthead
n_waitinglist 15213 . N struct waitinglist
n_vbc 5 . N struct vbc
n_wrk 174 . N worker threads
n_wrk_create 10484 0.02 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 514194 1.21 N queued work requests
n_wrk_drop 0 0.00 N dropped work requests
n_backend 1 . N backends
n_expired 4835952 . N expired objects
n_lru_nuked 0 . N LRU nuked objects
n_lru_moved 33485426 . N LRU moved objects
losthdr 0 0.00 HTTP header overflows
n_objsendfile 0 0.00 Objects sent with sendfile
n_objwrite 2351109391 5533.48 Objects sent with write
n_objoverflow 0 0.00 Objects overflowing workspace
s_sess 5990506 14.10 Total Sessions
s_req 2351555664 5534.53 Total Requests
s_pipe 0 0.00 Total pipe
s_pass 302120 0.71 Total pass
s_fetch 5138525 12.09 Total fetch
s_hdrbytes 544265355452 1280961.94 Total header bytes
s_bodybytes 3089476577758 7271272.85 Total body bytes
sess_closed 227804 0.54 Session Closed
sess_pipeline 0 0.00 Session Pipeline
sess_readahead 0 0.00 Session Read Ahead
sess_linger 2209279166 5199.67 Session Linger
sess_herd 323937467 762.41 Session herd
shm_records 89745845415 211222.36 SHM records
shm_writes 2562338698 6030.62 SHM writes
shm_flushes 62 0.00 SHM flushes due to overflow
shm_cont 27674729 65.13 SHM MTX contention
shm_cycles 43605 0.10 SHM cycles through buffer
sms_nreq 22 0.00 SMS allocator requests
sms_nobj 0 . SMS outstanding allocations
sms_nbytes 0 . SMS outstanding bytes
sms_balloc 8856 . SMS bytes allocated
sms_bfree 8856 . SMS bytes freed
backend_req 5138625 12.09 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 2351224626 5533.75 HCB Lookups without lock
hcb_lock 1666108 3.92 HCB Lookups with lock
hcb_insert 1666107 3.92 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 424888 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 2355834985 5544.60 Gunzip operations
LCK.sms.creat 1 0.00 Created locks
LCK.sms.destroy 0 0.00 Destroyed locks
LCK.sms.locks 66 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 2 0.00 Created locks
LCK.sma.destroy 0 0.00 Destroyed locks
LCK.sma.locks 24799574 58.37 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 3334164 7.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 32230 0.08 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 1251 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 5999643 14.12 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 155943114 367.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 25245 0.06 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 649162540 1527.84 Lock Operations
LCK.wq.colls 0 0.00 Collisions
LCK.objhdr.creat 1676572 3.95 Created locks
LCK.objhdr.destroy 1674713 3.94 Destroyed locks
LCK.objhdr.locks 9417295559 22164.18 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 10095406 23.76 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 4836405 11.38 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 141594 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 10095484 23.76 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 22541 0.05 Lock Operations
LCK.vbe.colls 0 0.00 Collisions
LCK.backend.creat 1 0.00 Created locks
LCK.backend.destroy 0 0.00 Destroyed locks
LCK.backend.locks 13459516 31.68 Lock Operations
LCK.backend.colls 0 0.00 Collisions
SMA.s0.c_req 9672832 22.77 Allocator requests
SMA.s0.c_fail 0 0.00 Allocator failures
SMA.s0.c_bytes 637361546992 1500069.54 Bytes allocated
SMA.s0.c_freed 637360393374 1500066.83 Bytes freed
SMA.s0.g_alloc 906 . Allocations outstanding
SMA.s0.g_bytes 1153618 . Bytes outstanding
SMA.s0.g_space 1072588206 . Bytes available
SMA.Transient.c_req 309204 0.73 Allocator requests
SMA.Transient.c_fail 0 0.00 Allocator failures
SMA.Transient.c_bytes 212330558 499.73 Bytes allocated
SMA.Transient.c_freed 212330558 499.73 Bytes freed
SMA.Transient.g_alloc 0 . Allocations outstanding
SMA.Transient.g_bytes 0 . Bytes outstanding
SMA.Transient.g_space 0 . Bytes available
VBE.default(172.29.101.121,,8080).vcls 1 . VCL
references
VBE.default(172.29.101.121,,8080).happy 0 . Happy
health probes
------------------------------
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 -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 30.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]
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]
listen_address 0.0.0.0:10300
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]
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 60 [seconds]
sess_timeout 5 [seconds]
sess_workspace 65536 [bytes]
session_linger 0 [ms]
session_max 100000 [sessions]
shm_reclen 255 [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 60 [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]
vcc_err_unref on [bool]
vcl_trace off [bool]
waiter default (epoll, poll)
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <https://www.varnish-cache.org/lists/pipermail/varnish-misc/attachments/20120523/621e27f1/attachment-0001.html>
More information about the varnish-misc
mailing list