Varnish 3 client_drop problem

Lei Wang leiwang at rhapsody.com
Mon Jan 14 23:58:23 CET 2013


Thanks for the information. Looks like there are memory leak at some place.

Varnish version is 3.0.3.

Lei

On Sun, Jan 13, 2013 at 11:52 AM, Streuhofer, Manuel <m.streuhofer at faz.de>wrote:

>  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 -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/20130114/0c4b280d/attachment-0001.html>


More information about the varnish-misc mailing list