Varnish 3 client_drop problem

Streuhofer, Manuel m.streuhofer at FAZ.DE
Sun Jan 13 20:52:57 CET 2013


I'm gonna guess here that the exact Version of Varnish you are using is 3.0.0
This version has a bug which causes your sessions to be counted upwards only.
Once you hit 100.000 sessions it will start dropping clients.
I'm surprised you didn't run into problems way before that. Each session means one open file handle.

Here's your problem:

n_sess_mem              100000          .   N struct sess_mem
n_sess                   99996          .   N struct sess

There are two solutions. The better one would be to upgrade since this was not the only ugly bug in this version. You'll be better of. The quick one is to turn off hyper threading. See: https://www.varnish-cache.org/trac/ticket/897


________________________________
From: varnish-misc-bounces at varnish-cache.org [varnish-misc-bounces at varnish-cache.org] on behalf of Lei Wang [leiwang at rhapsody.com]
Sent: Friday, January 11, 2013 10:07 PM
To: varnish-misc at varnish-cache.org
Subject: Varnish 3 client_drop problem

Hi,

Need help on one problem.

After few days, Varnish suddenly shows many client_drop error. Then response very slowly. I have to restart Varnish to fix it.
Vanish command as following:
/usr/sbin/varnishd -P /var/run/varnish80.pid -a :80 -f /etc/varnish/varnish80.vcl -T 127.0.0.1:6080<http://127.0.0.1:6080> -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

Below is the varnishstat result.
client_conn            1050088         2.58 Client connections accepted
client_drop             481044         1.18 Connection dropped, no sess/wrk
client_req            53255991       130.93 Client requests received
cache_hit             49915997       122.71 Cache hits
cache_hitpass                0         0.00 Cache hits for pass
cache_miss             3098734         7.62 Cache misses
backend_conn             23622         0.06 Backend conn. success
backend_unhealthy            0         0.00 Backend conn. not attempted
backend_busy                 0         0.00 Backend conn. too many
backend_fail                49         0.00 Backend conn. failures
backend_reuse          3076713         7.56 Backend conn. reuses
backend_toolate           4640         0.01 Backend conn. was closed
backend_recycle        3081374         7.58 Backend conn. recycles
backend_retry             1858         0.00 Backend conn. retry
fetch_head                  63         0.00 Fetch head
fetch_length           1122064         2.76 Fetch with Length
fetch_chunked          1959269         4.82 Fetch chunked
fetch_eof                    0         0.00 Fetch EOF
fetch_bad                    0         0.00 Fetch had bad headers
fetch_close               3641         0.01 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              100000          .   N struct sess_mem
n_sess                   99996          .   N struct sess
n_object                384255          .   N struct object
n_vampireobject              0          .   N unresurrected objects
n_objectcore            384362          .   N struct objectcore
n_objecthead            386502          .   N struct objecthead
n_waitinglist            22165          .   N struct waitinglist
n_vbc                       15          .   N struct vbc
n_wrk                      800          .   N worker threads
n_wrk_create               800         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                 0         0.00 N queued work requests
n_wrk_drop                   0         0.00 N dropped work requests
n_backend                   10          .   N backends
n_expired              2700698          .   N expired objects
n_lru_nuked                  0          .   N LRU nuked objects
n_lru_moved            6742713          .   N LRU moved objects
losthdr                      0         0.00 HTTP header overflows
n_objsendfile                0         0.00 Objects sent with sendfile
n_objwrite            33131257        81.45 Objects sent with write
n_objoverflow                0         0.00 Objects overflowing workspace
s_sess                  569070         1.40 Total Sessions
s_req                 53255991       130.93 Total Requests
s_pipe                      12         0.00 Total pipe
s_pass                      84         0.00 Total pass
s_fetch                3085037         7.58 Total fetch
s_hdrbytes         23233920070     57118.78 Total header bytes
s_bodybytes       511406013002   1257251.76 Total body bytes
sess_closed             268273         0.66 Session Closed
sess_pipeline                0         0.00 Session Pipeline
sess_readahead               0         0.00 Session Read Ahead
sess_linger           52902973       130.06 Session Linger
sess_herd             19131516        47.03 Session herd
shm_records         2474975941      6084.54 SHM records
shm_writes            80791017       198.62 SHM writes
shm_flushes                  0         0.00 SHM flushes due to overflow
shm_cont                 23501         0.06 SHM MTX contention
shm_cycles                 889         0.00 SHM cycles through buffer
sms_nreq                154946         0.38 SMS allocator requests
sms_nobj                     0          .   SMS outstanding allocations
sms_nbytes                   0          .   SMS outstanding bytes
sms_balloc            65340505          .   SMS bytes allocated
sms_bfree             65340505          .   SMS bytes freed
backend_req            3100325         7.62 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_gone                   1          .   N total gone 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            53113990       130.58 HCB Lookups without lock
hcb_lock               2909158         7.15 HCB Lookups with lock
hcb_insert             2909154         7.15 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                  406765         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                        1          .   Loaded VMODs
n_gzip                       0         0.00 Gzip operations
n_gunzip                     0         0.00 Gunzip operations
LCK.sms.creat                1         0.00 Created locks
LCK.sms.destroy              0         0.00 Destroyed locks
LCK.sms.locks           464838         1.14 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         13844221        34.03 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          5436356        13.36 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           165593         0.41 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          569072         1.40 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        1173472         2.88 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          1334044         3.28 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                   1         0.00 Created locks
LCK.wq.destroy                 0         0.00 Destroyed locks
LCK.wq.locks            39531997        97.19 Lock Operations
LCK.wq.colls                   0         0.00 Collisions
LCK.objhdr.creat         2909259         7.15 Created locks
LCK.objhdr.destroy       2522760         6.20 Destroyed locks
LCK.objhdr.locks       217895431       535.68 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            6191913        15.22 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            3084953         7.58 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             135560         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            6191997        15.22 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              47327         0.12 Lock Operations
LCK.vbe.colls                  0         0.00 Collisions
LCK.backend.creat             10         0.00 Created locks
LCK.backend.destroy            0         0.00 Destroyed locks
LCK.backend.locks        6233731        15.33 Lock Operations
LCK.backend.colls              0         0.00 Collisions
SMA.s0.c_req             6321249        15.54 Allocator requests
SMA.s0.c_fail                  0         0.00 Allocator failures
SMA.s0.c_bytes      300614422863    739037.09 Bytes allocated
SMA.s0.c_freed      289845281665    712562.00 Bytes freed
SMA.s0.g_alloc            768495          .   Allocations outstanding
SMA.s0.g_bytes       10769141198          .   Bytes outstanding
SMA.s0.g_space       15000662578          .   Bytes available
SMA.Transient.c_req         3656         0.01 Allocator requests
SMA.Transient.c_fail           0         0.00 Allocator failures
SMA.Transient.c_bytes     43886078       107.89 Bytes allocated
SMA.Transient.c_freed     43882627       107.88 Bytes freed
SMA.Transient.g_alloc            4          .   Allocations outstanding
SMA.Transient.g_bytes         3451          .   Bytes outstanding
SMA.Transient.g_space            0          .   Bytes available
VBE.rdsmetadata(10.150.16.2,,80).vcls            1          .   VCL references
VBE.rdsmetadata(10.150.16.2,,80).happy           0          .   Happy health probes


Thanks,

Lei
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <https://www.varnish-cache.org/lists/pipermail/varnish-misc/attachments/20130113/c8be9e67/attachment-0001.html>


More information about the varnish-misc mailing list