<span style="font-family: Arial;">What do you see in your varnishlog? <br><br>Sent from my Verizon Wireless 4G LTE Smartphone<br><br><div id="htc_header" style="">----- Reply message -----<br>From: "Lei Wang" <leiwang@rhapsody.com><br>To: <varnish-misc@varnish-cache.org><br>Subject: Varnish 3 client_drop problem<br>Date: Fri, Jan 11, 2013 4:07 PM<br><br></div></span><br>Hi,<br><br>Need help on one problem.<br><br>After few days, Varnish suddenly shows many client_drop error. Then response very slowly. I have to restart Varnish to fix it.<br>Vanish command as following:<br>/usr/sbin/varnishd -P /var/run/varnish80.pid -a :80 -f /etc/varnish/varnish80.vcl -T <a href="http://127.0.0.1:6080">127.0.0.1:6080</a> -t 120 -w 1,1000,120 -u varnish -g varnish -i varnish80 -S /etc/varnish/secret -p thread_pool_add_delay 2 -p thread_pools 2 -p thread_pool_min 100 -p thread_pool_max 2000 -p session_linger 50 -p sess_workspace 65536 -p http_req_hdr_len 8192 -p http_gzip_support off -n varnish80 -s malloc,24G<br>
<br>Below is the varnishstat result.<br>client_conn 1050088 2.58 Client connections accepted<br><b style="color:rgb(255,0,0)">client_drop 481044 1.18 Connection dropped, no sess/wrk</b><br>
client_req 53255991 130.93 Client requests received<br>cache_hit 49915997 122.71 Cache hits<br>cache_hitpass 0 0.00 Cache hits for pass<br>cache_miss 3098734 7.62 Cache misses<br>
backend_conn 23622 0.06 Backend conn. success<br>backend_unhealthy 0 0.00 Backend conn. not attempted<br>backend_busy 0 0.00 Backend conn. too many<br>backend_fail 49 0.00 Backend conn. failures<br>
backend_reuse 3076713 7.56 Backend conn. reuses<br>backend_toolate 4640 0.01 Backend conn. was closed<br>backend_recycle 3081374 7.58 Backend conn. recycles<br>backend_retry 1858 0.00 Backend conn. retry<br>
fetch_head 63 0.00 Fetch head<br>fetch_length 1122064 2.76 Fetch with Length<br>fetch_chunked 1959269 4.82 Fetch chunked<br>fetch_eof 0 0.00 Fetch EOF<br>
fetch_bad 0 0.00 Fetch had bad headers<br>fetch_close 3641 0.01 Fetch wanted close<br>fetch_oldhttp 0 0.00 Fetch pre HTTP/1.1 closed<br>fetch_zero 0 0.00 Fetch zero len<br>
fetch_failed 0 0.00 Fetch failed<br>fetch_1xx 0 0.00 Fetch no body (1xx)<br>fetch_204 0 0.00 Fetch no body (204)<br>fetch_304 0 0.00 Fetch no body (304)<br>
n_sess_mem 100000 . N struct sess_mem<br>n_sess 99996 . N struct sess<br>n_object 384255 . N struct object<br>n_vampireobject 0 . N unresurrected objects<br>
n_objectcore 384362 . N struct objectcore<br>n_objecthead 386502 . N struct objecthead<br>n_waitinglist 22165 . N struct waitinglist<br>n_vbc 15 . N struct vbc<br>
n_wrk 800 . N worker threads<br>n_wrk_create 800 0.00 N worker threads created<br>n_wrk_failed 0 0.00 N worker threads not created<br>n_wrk_max 0 0.00 N worker threads limited<br>
n_wrk_lqueue 0 0.00 work request queue length<br>n_wrk_queued 0 0.00 N queued work requests<br>n_wrk_drop 0 0.00 N dropped work requests<br>n_backend 10 . N backends<br>
n_expired 2700698 . N expired objects<br>n_lru_nuked 0 . N LRU nuked objects<br>n_lru_moved 6742713 . N LRU moved objects<br>losthdr 0 0.00 HTTP header overflows<br>
n_objsendfile 0 0.00 Objects sent with sendfile<br>n_objwrite 33131257 81.45 Objects sent with write<br>n_objoverflow 0 0.00 Objects overflowing workspace<br>
s_sess 569070 1.40 Total Sessions<br>s_req 53255991 130.93 Total Requests<br>s_pipe 12 0.00 Total pipe<br>s_pass 84 0.00 Total pass<br>
s_fetch 3085037 7.58 Total fetch<br>s_hdrbytes 23233920070 57118.78 Total header bytes<br>s_bodybytes 511406013002 1257251.76 Total body bytes<br>sess_closed 268273 0.66 Session Closed<br>
sess_pipeline 0 0.00 Session Pipeline<br>sess_readahead 0 0.00 Session Read Ahead<br>sess_linger 52902973 130.06 Session Linger<br>sess_herd 19131516 47.03 Session herd<br>
shm_records 2474975941 6084.54 SHM records<br>shm_writes 80791017 198.62 SHM writes<br>shm_flushes 0 0.00 SHM flushes due to overflow<br>shm_cont 23501 0.06 SHM MTX contention<br>
shm_cycles 889 0.00 SHM cycles through buffer<br>sms_nreq 154946 0.38 SMS allocator requests<br>sms_nobj 0 . SMS outstanding allocations<br>sms_nbytes 0 . SMS outstanding bytes<br>
sms_balloc 65340505 . SMS bytes allocated<br>sms_bfree 65340505 . SMS bytes freed<br>backend_req 3100325 7.62 Backend requests made<br>n_vcl 1 0.00 N vcl total<br>
n_vcl_avail 1 0.00 N vcl available<br>n_vcl_discard 0 0.00 N vcl discarded<br>n_ban 1 . N total active bans<br>n_ban_gone 1 . N total gone bans<br>
n_ban_add 1 0.00 N new bans added<br>n_ban_retire 0 0.00 N old bans deleted<br>n_ban_obj_test 0 0.00 N objects tested<br>n_ban_re_test 0 0.00 N regexps tested against<br>
n_ban_dups 0 0.00 N duplicate bans removed<br>hcb_nolock 53113990 130.58 HCB Lookups without lock<br>hcb_lock 2909158 7.15 HCB Lookups with lock<br>hcb_insert 2909154 7.15 HCB Inserts<br>
esi_errors 0 0.00 ESI parse errors (unlock)<br>esi_warnings 0 0.00 ESI parse warnings (unlock)<br>accept_fail 0 0.00 Accept failures<br>client_drop_late 0 0.00 Connection dropped late<br>
uptime 406765 1.00 Client uptime<br>dir_dns_lookups 0 0.00 DNS director lookups<br>dir_dns_failed 0 0.00 DNS director failed lookups<br>dir_dns_hit 0 0.00 DNS director cached lookups hit<br>
dir_dns_cache_full 0 0.00 DNS director full dnscache<br>vmods 1 . Loaded VMODs<br>n_gzip 0 0.00 Gzip operations<br>n_gunzip 0 0.00 Gunzip operations<br>
LCK.sms.creat 1 0.00 Created locks<br>LCK.sms.destroy 0 0.00 Destroyed locks<br>LCK.sms.locks 464838 1.14 Lock Operations<br>LCK.sms.colls 0 0.00 Collisions<br>
LCK.smp.creat 0 0.00 Created locks<br>LCK.smp.destroy 0 0.00 Destroyed locks<br>LCK.smp.locks 0 0.00 Lock Operations<br>LCK.smp.colls 0 0.00 Collisions<br>
LCK.sma.creat 2 0.00 Created locks<br>LCK.sma.destroy 0 0.00 Destroyed locks<br>LCK.sma.locks 13844221 34.03 Lock Operations<br>LCK.sma.colls 0 0.00 Collisions<br>
LCK.smf.creat 0 0.00 Created locks<br>LCK.smf.destroy 0 0.00 Destroyed locks<br>LCK.smf.locks 0 0.00 Lock Operations<br>LCK.smf.colls 0 0.00 Collisions<br>
LCK.hsl.creat 0 0.00 Created locks<br>LCK.hsl.destroy 0 0.00 Destroyed locks<br>LCK.hsl.locks 0 0.00 Lock Operations<br>LCK.hsl.colls 0 0.00 Collisions<br>
LCK.hcb.creat 1 0.00 Created locks<br>LCK.hcb.destroy 0 0.00 Destroyed locks<br>LCK.hcb.locks 5436356 13.36 Lock Operations<br>LCK.hcb.colls 0 0.00 Collisions<br>
LCK.hcl.creat 0 0.00 Created locks<br>LCK.hcl.destroy 0 0.00 Destroyed locks<br>LCK.hcl.locks 0 0.00 Lock Operations<br>LCK.hcl.colls 0 0.00 Collisions<br>
LCK.vcl.creat 1 0.00 Created locks<br>LCK.vcl.destroy 0 0.00 Destroyed locks<br>LCK.vcl.locks 165593 0.41 Lock Operations<br>LCK.vcl.colls 0 0.00 Collisions<br>
LCK.stat.creat 1 0.00 Created locks<br>LCK.stat.destroy 0 0.00 Destroyed locks<br>LCK.stat.locks 569072 1.40 Lock Operations<br>LCK.stat.colls 0 0.00 Collisions<br>
LCK.sessmem.creat 1 0.00 Created locks<br>LCK.sessmem.destroy 0 0.00 Destroyed locks<br>LCK.sessmem.locks 1173472 2.88 Lock Operations<br>LCK.sessmem.colls 0 0.00 Collisions<br>
LCK.wstat.creat 1 0.00 Created locks<br>LCK.wstat.destroy 0 0.00 Destroyed locks<br>LCK.wstat.locks 1334044 3.28 Lock Operations<br>LCK.wstat.colls 0 0.00 Collisions<br>
LCK.herder.creat 1 0.00 Created locks<br>LCK.herder.destroy 0 0.00 Destroyed locks<br>LCK.herder.locks 1 0.00 Lock Operations<br>LCK.herder.colls 0 0.00 Collisions<br>
LCK.wq.creat 1 0.00 Created locks<br>LCK.wq.destroy 0 0.00 Destroyed locks<br>LCK.wq.locks 39531997 97.19 Lock Operations<br>LCK.wq.colls 0 0.00 Collisions<br>
LCK.objhdr.creat 2909259 7.15 Created locks<br>LCK.objhdr.destroy 2522760 6.20 Destroyed locks<br>LCK.objhdr.locks 217895431 535.68 Lock Operations<br>LCK.objhdr.colls 0 0.00 Collisions<br>
LCK.exp.creat 1 0.00 Created locks<br>LCK.exp.destroy 0 0.00 Destroyed locks<br>LCK.exp.locks 6191913 15.22 Lock Operations<br>LCK.exp.colls 0 0.00 Collisions<br>
LCK.lru.creat 2 0.00 Created locks<br>LCK.lru.destroy 0 0.00 Destroyed locks<br>LCK.lru.locks 3084953 7.58 Lock Operations<br>LCK.lru.colls 0 0.00 Collisions<br>
LCK.cli.creat 1 0.00 Created locks<br>LCK.cli.destroy 0 0.00 Destroyed locks<br>LCK.cli.locks 135560 0.33 Lock Operations<br>LCK.cli.colls 0 0.00 Collisions<br>
LCK.ban.creat 1 0.00 Created locks<br>LCK.ban.destroy 0 0.00 Destroyed locks<br>LCK.ban.locks 6191997 15.22 Lock Operations<br>LCK.ban.colls 0 0.00 Collisions<br>
LCK.vbp.creat 1 0.00 Created locks<br>LCK.vbp.destroy 0 0.00 Destroyed locks<br>LCK.vbp.locks 0 0.00 Lock Operations<br>LCK.vbp.colls 0 0.00 Collisions<br>
LCK.vbe.creat 1 0.00 Created locks<br>LCK.vbe.destroy 0 0.00 Destroyed locks<br>LCK.vbe.locks 47327 0.12 Lock Operations<br>LCK.vbe.colls 0 0.00 Collisions<br>
LCK.backend.creat 10 0.00 Created locks<br>LCK.backend.destroy 0 0.00 Destroyed locks<br>LCK.backend.locks 6233731 15.33 Lock Operations<br>LCK.backend.colls 0 0.00 Collisions<br>
SMA.s0.c_req 6321249 15.54 Allocator requests<br>SMA.s0.c_fail 0 0.00 Allocator failures<br>SMA.s0.c_bytes 300614422863 739037.09 Bytes allocated<br>SMA.s0.c_freed 289845281665 712562.00 Bytes freed<br>
SMA.s0.g_alloc 768495 . Allocations outstanding<br>SMA.s0.g_bytes 10769141198 . Bytes outstanding<br>SMA.s0.g_space 15000662578 . Bytes available<br>SMA.Transient.c_req 3656 0.01 Allocator requests<br>
SMA.Transient.c_fail 0 0.00 Allocator failures<br>SMA.Transient.c_bytes 43886078 107.89 Bytes allocated<br>SMA.Transient.c_freed 43882627 107.88 Bytes freed<br>SMA.Transient.g_alloc 4 . Allocations outstanding<br>
SMA.Transient.g_bytes 3451 . Bytes outstanding<br>SMA.Transient.g_space 0 . Bytes available<br>VBE.rdsmetadata(10.150.16.2,,80).vcls 1 . VCL references<br>VBE.rdsmetadata(10.150.16.2,,80).happy 0 . Happy health probes<br>
<br><br>Thanks,<br><br>Lei<br>