Varnish - high session_linger and session herd

Barry Conroy barrycie at aol.com
Mon May 21 23:12:06 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/20120521/319e9a5d/attachment-0001.html>


More information about the varnish-misc mailing list