Hi Matt,<div>It looks like you really need to bump up the number of worker threads. From your stats:</div><div><br></div><div><p class="MsoNormal"><span style="font-size: 10pt; color: black; ">n_wrk_queue 2861 0.02 N queued work requests<u></u><u></u></span></p>
<p class="MsoNormal"><span style="font-size: 10pt; color: black; ">n_wrk_overflow 83534 0.52 N overflowed work requests<u></u><u></u></span></p><p class="MsoNormal"><span style="font-size: 10pt; color: black; ">n_wrk_drop 10980 0.07 N dropped work requests</span></p>
<p class="MsoNormal"><span style="font-size: 10pt; color: black; "><br></span></p><p class="MsoNormal"><span style="font-size: 10pt; color: black; ">You have a lot of requests that are on the queue waiting for a worker and you have a lot of requests where varnish has given up trying to fullfil with a worker. You can bump the number of works up using the -w command line option to varnishd. I would suggest something like -w 400,1000,120 to start with (the default is -w2,500,300). This says use 400 at a minimum, 1000 as the maximum, and set the timeout to 120s. According to the <a href="https://www.varnish-cache.org/trac/wiki/StatsExplained">stats explanation doc</a> your n_wrk_queue and n_wrk_drop should be 0. If you see these numbers going up again, use -w 500,2000,120 or something like that.</span></p>
<p class="MsoNormal"><span style="font-size: 10pt; color: black; "><br></span></p><p class="MsoNormal"><span style="font-size: 10pt; color: black; ">Hope this helps,</span></p><p class="MsoNormal"><span style="font-size: 10pt; color: black; ">Damon</span></p>
<br><div class="gmail_quote">On Thu, Sep 29, 2011 at 4:34 PM, Matt Schurenko <span dir="ltr"><<a href="mailto:MSchurenko@airg.com">MSchurenko@airg.com</a>></span> wrote:<br><blockquote class="gmail_quote" style="margin:0 0 0 .8ex;border-left:1px #ccc solid;padding-left:1ex;">
<div lang="EN-CA" link="blue" vlink="purple"><div><p class="MsoNormal"><span style="font-size:10.0pt;color:black">I’ve been having this problem for a couple weeks now on one of our varnish servers. I have posted a couple times already. What happens is that the server in questions runs fine until the cache gets full. When it starts to lru nuke the number of worker threads jumps up to thread_pool_max and varnish stops responding to any client requests. I have tried this with Centos5.4, 5.7 and now Slackware (all 64-bit ) and the behaviour is the same. <u></u><u></u></span></p>
<p class="MsoNormal"><span style="font-size:10.0pt;color:black"><u></u> <u></u></span></p><p class="MsoNormal"><span style="font-size:10.0pt;color:black">I am using varnish version 2.1.5 on a Dell C6105 with 48GB of RAM.<u></u><u></u></span></p>
<p class="MsoNormal"><span style="font-size:10.0pt;color:black"><u></u> <u></u></span></p><p class="MsoNormal"><span style="font-size:10.0pt;color:black">Here is my varnishd command line:<u></u><u></u></span></p><p class="MsoNormal">
<span style="font-size:10.0pt;color:black"><u></u> <u></u></span></p><p class="MsoNormal"><span style="font-size:10.0pt;color:black">/usr/local/sbin/varnishd -s file,/tmp/varnish-cache,48g -T <a href="http://127.0.0.1:2000" target="_blank">127.0.0.1:2000</a> -a <a href="http://0.0.0.0:80" target="_blank">0.0.0.0:80</a> -t 604800 -f /usr/local/etc/varnish/default.vcl -p http_headers 384 -p connect_timeout 4.0<u></u><u></u></span></p>
<p class="MsoNormal"><span style="font-size:10.0pt;color:black"><u></u> <u></u></span></p><p class="MsoNormal"><span style="font-size:10.0pt;color:black">Here is the output from varnishstat -1:<u></u><u></u></span></p><p class="MsoNormal">
<span style="font-size:10.0pt;color:black"><u></u> <u></u></span></p><p class="MsoNormal"><span style="font-size:10.0pt;color:black">client_conn 38582763 240.38 Client connections accepted<u></u><u></u></span></p>
<p class="MsoNormal"><span style="font-size:10.0pt;color:black">client_drop 10950 0.07 Connection dropped, no sess/wrk<u></u><u></u></span></p><p class="MsoNormal"><span style="font-size:10.0pt;color:black">client_req 38298994 238.61 Client requests received<u></u><u></u></span></p>
<p class="MsoNormal"><span style="font-size:10.0pt;color:black">cache_hit 32513762 202.57 Cache hits<u></u><u></u></span></p><p class="MsoNormal"><span style="font-size:10.0pt;color:black">cache_hitpass 0 0.00 Cache hits for pass<u></u><u></u></span></p>
<p class="MsoNormal"><span style="font-size:10.0pt;color:black">cache_miss 5784476 36.04 Cache misses<u></u><u></u></span></p><p class="MsoNormal"><span style="font-size:10.0pt;color:black">backend_conn 5725540 35.67 Backend conn. success<u></u><u></u></span></p>
<p class="MsoNormal"><span style="font-size:10.0pt;color:black">backend_unhealthy 0 0.00 Backend conn. not attempted<u></u><u></u></span></p><p class="MsoNormal"><span style="font-size:10.0pt;color:black">backend_busy 0 0.00 Backend conn. too many<u></u><u></u></span></p>
<p class="MsoNormal"><span style="font-size:10.0pt;color:black">backend_fail 1383 0.01 Backend conn. failures<u></u><u></u></span></p><p class="MsoNormal"><span style="font-size:10.0pt;color:black">backend_reuse 60837 0.38 Backend conn. reuses<u></u><u></u></span></p>
<p class="MsoNormal"><span style="font-size:10.0pt;color:black">backend_toolate 33 0.00 Backend conn. was closed<u></u><u></u></span></p><p class="MsoNormal"><span style="font-size:10.0pt;color:black">backend_recycle 60870 0.38 Backend conn. recycles<u></u><u></u></span></p>
<p class="MsoNormal"><span style="font-size:10.0pt;color:black">backend_unused 0 0.00 Backend conn. unused<u></u><u></u></span></p><p class="MsoNormal"><span style="font-size:10.0pt;color:black">fetch_head 6 0.00 Fetch head<u></u><u></u></span></p>
<p class="MsoNormal"><span style="font-size:10.0pt;color:black">fetch_length 93631 0.58 Fetch with Length<u></u><u></u></span></p><p class="MsoNormal"><span style="font-size:10.0pt;color:black">fetch_chunked 5689433 35.45 Fetch chunked<u></u><u></u></span></p>
<p class="MsoNormal"><span style="font-size:10.0pt;color:black">fetch_eof 0 0.00 Fetch EOF<u></u><u></u></span></p><p class="MsoNormal"><span style="font-size:10.0pt;color:black">fetch_bad 0 0.00 Fetch had bad headers<u></u><u></u></span></p>
<p class="MsoNormal"><span style="font-size:10.0pt;color:black">fetch_close 107 0.00 Fetch wanted close<u></u><u></u></span></p><p class="MsoNormal"><span style="font-size:10.0pt;color:black">fetch_oldhttp 0 0.00 Fetch pre HTTP/1.1 closed<u></u><u></u></span></p>
<p class="MsoNormal"><span style="font-size:10.0pt;color:black">fetch_zero 0 0.00 Fetch zero len<u></u><u></u></span></p><p class="MsoNormal"><span style="font-size:10.0pt;color:black">fetch_failed 1 0.00 Fetch failed<u></u><u></u></span></p>
<p class="MsoNormal"><span style="font-size:10.0pt;color:black">n_sess_mem 7138 . N struct sess_mem<u></u><u></u></span></p><p class="MsoNormal"><span style="font-size:10.0pt;color:black">n_sess 6970 . N struct sess<u></u><u></u></span></p>
<p class="MsoNormal"><span style="font-size:10.0pt;color:black">n_object 5047123 . N struct object<u></u><u></u></span></p><p class="MsoNormal"><span style="font-size:10.0pt;color:black">n_vampireobject 0 . N unresurrected objects<u></u><u></u></span></p>
<p class="MsoNormal"><span style="font-size:10.0pt;color:black">n_objectcore 5048435 . N struct objectcore<u></u><u></u></span></p><p class="MsoNormal"><span style="font-size:10.0pt;color:black">n_objecthead 4955641 . N struct objecthead<u></u><u></u></span></p>
<p class="MsoNormal"><span style="font-size:10.0pt;color:black">n_smf 10139770 . N struct smf<u></u><u></u></span></p><p class="MsoNormal"><span style="font-size:10.0pt;color:black">n_smf_frag 295671 . N small free smf<u></u><u></u></span></p>
<p class="MsoNormal"><span style="font-size:10.0pt;color:black">n_smf_large 0 . N large free smf<u></u><u></u></span></p><p class="MsoNormal"><span style="font-size:10.0pt;color:black">n_vbe_conn 2997 . N struct vbe_conn<u></u><u></u></span></p>
<p class="MsoNormal"><span style="font-size:10.0pt;color:black">n_wrk 3000 . N worker threads<u></u><u></u></span></p><p class="MsoNormal"><span style="font-size:10.0pt;color:black">n_wrk_create 5739 0.04 N worker threads created<u></u><u></u></span></p>
<p class="MsoNormal"><span style="font-size:10.0pt;color:black">n_wrk_failed 0 0.00 N worker threads not created<u></u><u></u></span></p><p class="MsoNormal"><span style="font-size:10.0pt;color:black">n_wrk_max 4063 0.03 N worker threads limited<u></u><u></u></span></p>
<p class="MsoNormal"><span style="font-size:10.0pt;color:black">n_wrk_queue 2861 0.02 N queued work requests<u></u><u></u></span></p><p class="MsoNormal"><span style="font-size:10.0pt;color:black">n_wrk_overflow 83534 0.52 N overflowed work requests<u></u><u></u></span></p>
<p class="MsoNormal"><span style="font-size:10.0pt;color:black">n_wrk_drop 10980 0.07 N dropped work requests<u></u><u></u></span></p><p class="MsoNormal"><span style="font-size:10.0pt;color:black">n_backend 2 . N backends<u></u><u></u></span></p>
<p class="MsoNormal"><span style="font-size:10.0pt;color:black">n_expired 2179 . N expired objects<u></u><u></u></span></p><p class="MsoNormal"><span style="font-size:10.0pt;color:black">n_lru_nuked 862615 . N LRU nuked objects<u></u><u></u></span></p>
<p class="MsoNormal"><span style="font-size:10.0pt;color:black">n_lru_saved 0 . N LRU saved objects<u></u><u></u></span></p><p class="MsoNormal"><span style="font-size:10.0pt;color:black">n_lru_moved 27156180 . N LRU moved objects<u></u><u></u></span></p>
<p class="MsoNormal"><span style="font-size:10.0pt;color:black">n_deathrow 0 . N objects on deathrow<u></u><u></u></span></p><p class="MsoNormal"><span style="font-size:10.0pt;color:black">losthdr 0 0.00 HTTP header overflows<u></u><u></u></span></p>
<p class="MsoNormal"><span style="font-size:10.0pt;color:black">n_objsendfile 0 0.00 Objects sent with sendfile<u></u><u></u></span></p><p class="MsoNormal"><span style="font-size:10.0pt;color:black">n_objwrite 37294888 232.35 Objects sent with write<u></u><u></u></span></p>
<p class="MsoNormal"><span style="font-size:10.0pt;color:black">n_objoverflow 0 0.00 Objects overflowing workspace<u></u><u></u></span></p><p class="MsoNormal"><span style="font-size:10.0pt;color:black">s_sess 38566049 240.27 Total Sessions<u></u><u></u></span></p>
<p class="MsoNormal"><span style="font-size:10.0pt;color:black">s_req 38298994 238.61 Total Requests<u></u><u></u></span></p><p class="MsoNormal"><span style="font-size:10.0pt;color:black">s_pipe 0 0.00 Total pipe<u></u><u></u></span></p>
<p class="MsoNormal"><span style="font-size:10.0pt;color:black">s_pass 266 0.00 Total pass<u></u><u></u></span></p><p class="MsoNormal"><span style="font-size:10.0pt;color:black">s_fetch 5783176 36.03 Total fetch<u></u><u></u></span></p>
<p class="MsoNormal"><span style="font-size:10.0pt;color:black">s_hdrbytes 12570989864 78319.53 Total header bytes<u></u><u></u></span></p><p class="MsoNormal"><span style="font-size:10.0pt;color:black">s_bodybytes 151327304604 942796.38 Total body bytes<u></u><u></u></span></p>
<p class="MsoNormal"><span style="font-size:10.0pt;color:black">sess_closed 34673984 216.03 Session Closed<u></u><u></u></span></p><p class="MsoNormal"><span style="font-size:10.0pt;color:black">sess_pipeline 187 0.00 Session Pipeline<u></u><u></u></span></p>
<p class="MsoNormal"><span style="font-size:10.0pt;color:black">sess_readahead 321 0.00 Session Read Ahead<u></u><u></u></span></p><p class="MsoNormal"><span style="font-size:10.0pt;color:black">sess_linger 3929378 24.48 Session Linger<u></u><u></u></span></p>
<p class="MsoNormal"><span style="font-size:10.0pt;color:black">sess_herd 3929559 24.48 Session herd<u></u><u></u></span></p><p class="MsoNormal"><span style="font-size:10.0pt;color:black">shm_records <a href="tel:2025645664" value="+12025645664" target="_blank">2025645664</a> 12620.14 SHM records<u></u><u></u></span></p>
<p class="MsoNormal"><span style="font-size:10.0pt;color:black">shm_writes 169640580 1056.89 SHM writes<u></u><u></u></span></p><p class="MsoNormal"><span style="font-size:10.0pt;color:black">shm_flushes 41 0.00 SHM flushes due to overflow<u></u><u></u></span></p>
<p class="MsoNormal"><span style="font-size:10.0pt;color:black">shm_cont 580515 3.62 SHM MTX contention<u></u><u></u></span></p><p class="MsoNormal"><span style="font-size:10.0pt;color:black">shm_cycles 933 0.01 SHM cycles through buffer<u></u><u></u></span></p>
<p class="MsoNormal"><span style="font-size:10.0pt;color:black">sm_nreq 12431620 77.45 allocator requests<u></u><u></u></span></p><p class="MsoNormal"><span style="font-size:10.0pt;color:black">sm_nobj 9844099 . outstanding allocations<u></u><u></u></span></p>
<p class="MsoNormal"><span style="font-size:10.0pt;color:black">sm_balloc 43855261696 . bytes allocated<u></u><u></u></span></p><p class="MsoNormal"><span style="font-size:10.0pt;color:black">sm_bfree 7684345856 . bytes free<u></u><u></u></span></p>
<p class="MsoNormal"><span style="font-size:10.0pt;color:black">sma_nreq 0 0.00 SMA allocator requests<u></u><u></u></span></p><p class="MsoNormal"><span style="font-size:10.0pt;color:black">sma_nobj 0 . SMA outstanding allocations<u></u><u></u></span></p>
<p class="MsoNormal"><span style="font-size:10.0pt;color:black">sma_nbytes 0 . SMA outstanding bytes<u></u><u></u></span></p><p class="MsoNormal"><span style="font-size:10.0pt;color:black">sma_balloc 0 . SMA bytes allocated<u></u><u></u></span></p>
<p class="MsoNormal"><span style="font-size:10.0pt;color:black">sma_bfree 0 . SMA bytes free<u></u><u></u></span></p><p class="MsoNormal"><span style="font-size:10.0pt;color:black">sms_nreq 1566 0.01 SMS allocator requests<u></u><u></u></span></p>
<p class="MsoNormal"><span style="font-size:10.0pt;color:black">sms_nobj 0 . SMS outstanding allocations<u></u><u></u></span></p><p class="MsoNormal"><span style="font-size:10.0pt;color:black">sms_nbytes 0 . SMS outstanding bytes<u></u><u></u></span></p>
<p class="MsoNormal"><span style="font-size:10.0pt;color:black">sms_balloc 656154 . SMS bytes allocated<u></u><u></u></span></p><p class="MsoNormal"><span style="font-size:10.0pt;color:black">sms_bfree 656154 . SMS bytes freed<u></u><u></u></span></p>
<p class="MsoNormal"><span style="font-size:10.0pt;color:black">backend_req 5786381 36.05 Backend requests made<u></u><u></u></span></p><p class="MsoNormal"><span style="font-size:10.0pt;color:black">n_vcl 1 0.00 N vcl total<u></u><u></u></span></p>
<p class="MsoNormal"><span style="font-size:10.0pt;color:black">n_vcl_avail 1 0.00 N vcl available<u></u><u></u></span></p><p class="MsoNormal"><span style="font-size:10.0pt;color:black">n_vcl_discard 0 0.00 N vcl discarded<u></u><u></u></span></p>
<p class="MsoNormal"><span style="font-size:10.0pt;color:black">n_purge 218 . N total active purges<u></u><u></u></span></p><p class="MsoNormal"><span style="font-size:10.0pt;color:black">n_purge_add 218 0.00 N new purges added<u></u><u></u></span></p>
<p class="MsoNormal"><span style="font-size:10.0pt;color:black">n_purge_retire 0 0.00 N old purges deleted<u></u><u></u></span></p><p class="MsoNormal"><span style="font-size:10.0pt;color:black">n_purge_obj_test 588742 3.67 N objects tested<u></u><u></u></span></p>
<p class="MsoNormal"><span style="font-size:10.0pt;color:black">n_purge_re_test 120444323 750.39 N regexps tested against<u></u><u></u></span></p><p class="MsoNormal"><span style="font-size:10.0pt;color:black">n_purge_dups 0 0.00 N duplicate purges removed<u></u><u></u></span></p>
<p class="MsoNormal"><span style="font-size:10.0pt;color:black">hcb_nolock 38301670 238.63 HCB Lookups without lock<u></u><u></u></span></p><p class="MsoNormal"><span style="font-size:10.0pt;color:black">hcb_lock 5786309 36.05 HCB Lookups with lock<u></u><u></u></span></p>
<p class="MsoNormal"><span style="font-size:10.0pt;color:black">hcb_insert 5786305 36.05 HCB Inserts<u></u><u></u></span></p><p class="MsoNormal"><span style="font-size:10.0pt;color:black">esi_parse 0 0.00 Objects ESI parsed (unlock)<u></u><u></u></span></p>
<p class="MsoNormal"><span style="font-size:10.0pt;color:black">esi_errors 0 0.00 ESI parse errors (unlock)<u></u><u></u></span></p><p class="MsoNormal"><span style="font-size:10.0pt;color:black">accept_fail 0 0.00 Accept failures<u></u><u></u></span></p>
<p class="MsoNormal"><span style="font-size:10.0pt;color:black">client_drop_late 30 0.00 Connection dropped late<u></u><u></u></span></p><p class="MsoNormal"><span style="font-size:10.0pt;color:black">uptime 160509 1.00 Client uptime<u></u><u></u></span></p>
<p class="MsoNormal"><span style="font-size:10.0pt;color:black">backend_retry 25 0.00 Backend conn. retry<u></u><u></u></span></p><p class="MsoNormal"><span style="font-size:10.0pt;color:black">dir_dns_lookups 0 0.00 DNS director lookups<u></u><u></u></span></p>
<p class="MsoNormal"><span style="font-size:10.0pt;color:black">dir_dns_failed 0 0.00 DNS director failed lookups<u></u><u></u></span></p><p class="MsoNormal"><span style="font-size:10.0pt;color:black">dir_dns_hit 0 0.00 DNS director cached lookups hit<u></u><u></u></span></p>
<p class="MsoNormal"><span style="font-size:10.0pt;color:black">dir_dns_cache_full 0 0.00 DNS director full dnscache<u></u><u></u></span></p><p class="MsoNormal"><span style="font-size:10.0pt;color:black">fetch_1xx 0 0.00 Fetch no body (1xx)<u></u><u></u></span></p>
<p class="MsoNormal"><span style="font-size:10.0pt;color:black">fetch_204 0 0.00 Fetch no body (204)<u></u><u></u></span></p><p class="MsoNormal"><span style="font-size:10.0pt;color:black">fetch_304 0 0.00 Fetch no body (304)<u></u><u></u></span></p>
<p class="MsoNormal"><span style="font-size:10.0pt;color:black"><u></u> <u></u></span></p><p class="MsoNormal"><span style="font-size:10.0pt;color:black">Even though I have removed the server from our load balancer there are still a lot of requests going to the backend. Maybe these are all queued up requests that varnish is trying to fulfill? Here is some output from varnishlog –c when I try to connect with curl:<u></u><u></u></span></p>
<p class="MsoNormal"><span style="font-size:10.0pt;color:black"><u></u> <u></u></span></p><p class="MsoNormal"><span style="font-size:10.0pt;color:black">root@mvp14:~# varnishlog -c<u></u><u></u></span></p><p class="MsoNormal">
<span style="font-size:10.0pt;color:black"> 26 SessionOpen c 192.168.8.41 41942 <a href="http://0.0.0.0:80" target="_blank">0.0.0.0:80</a><u></u><u></u></span></p><p class="MsoNormal"><span style="font-size:10.0pt;color:black"> 26 ReqStart c 192.168.8.41 41942 2108342803<u></u><u></u></span></p>
<p class="MsoNormal"><span style="font-size:10.0pt;color:black"> 26 RxRequest c GET<u></u><u></u></span></p><p class="MsoNormal"><span style="font-size:10.0pt;color:black"> 26 RxURL c /<u></u><u></u></span></p>
<p class="MsoNormal"><span style="font-size:10.0pt;color:black"> 26 RxProtocol c HTTP/1.1<u></u><u></u></span></p><p class="MsoNormal"><span style="font-size:10.0pt;color:black"> 26 RxHeader c User-Agent: curl/7.21.4 (x86_64-unknown-linux-gnu) libcurl/7.21.4 OpenSSL/0.9.8n zlib/1.2.5 libidn/1.19<u></u><u></u></span></p>
<p class="MsoNormal"><span style="font-size:10.0pt;color:black"> 26 RxHeader c Host: <a href="http://mvp14.airg.com" target="_blank">mvp14.airg.com</a><u></u><u></u></span></p><p class="MsoNormal"><span style="font-size:10.0pt;color:black"> 26 RxHeader c Accept: */*<u></u><u></u></span></p>
<p class="MsoNormal"><span style="font-size:10.0pt;color:black"> 26 VCL_call c recv<u></u><u></u></span></p><p class="MsoNormal"><span style="font-size:10.0pt;color:black"> 26 VCL_return c lookup<u></u><u></u></span></p>
<p class="MsoNormal"><span style="font-size:10.0pt;color:black"> 26 VCL_call c hash<u></u><u></u></span></p><p class="MsoNormal"><span style="font-size:10.0pt;color:black"> 26 VCL_return c hash<u></u><u></u></span></p>
<p class="MsoNormal"><span style="font-size:10.0pt;color:black"><u></u> <u></u></span></p><p class="MsoNormal"><span style="font-size:10.0pt;color:black"><u></u> <u></u></span></p><p class="MsoNormal"><span style="font-size:10.0pt;color:black">The connection just hangs here until it times out.<u></u><u></u></span></p>
<p class="MsoNormal"><span style="font-size:10.0pt;color:black"><u></u> <u></u></span></p><p class="MsoNormal"><span style="font-size:10.0pt;color:black">Any help would be appreciated. We are trying to replace our squid caching layer with varnish. However if I can’t resolve this issue we will have to go back to squid.<u></u><u></u></span></p>
<p class="MsoNormal"><span style="font-size:10.0pt;color:black"><u></u> <u></u></span></p><p class="MsoNormal"><span style="font-size:10.0pt;color:black">Thanks,<u></u><u></u></span></p><p class="MsoNormal"><span style="font-size:10.0pt;color:black"><u></u> <u></u></span></p>
<font color="#888888"><p class="MsoNormal"><span style="font-size:10.0pt;color:black"><u></u> <u></u></span></p><p class="MsoNormal"><span style="font-size:10.0pt;color:black"><u></u> <u></u></span></p><div><p class="MsoNormal">
<b><span style="font-size:10.0pt;color:black">Matt Schurenko</span></b><span style="font-size:12.0pt;font-family:"Times New Roman","serif";color:black"><br></span><span style="font-size:10.0pt;color:gray">Systems Administrator</span><span style="font-size:12.0pt;font-family:"Times New Roman","serif";color:black"> <u></u><u></u></span></p>
</div></font></div></div><br>_______________________________________________<br>
varnish-misc mailing list<br>
<a href="mailto:varnish-misc@varnish-cache.org">varnish-misc@varnish-cache.org</a><br>
<a href="https://www.varnish-cache.org/lists/mailman/listinfo/varnish-misc" target="_blank">https://www.varnish-cache.org/lists/mailman/listinfo/varnish-misc</a><br></blockquote></div><br></div>