Question about varnish memory usage

Adam Schumacher adam.schumacher at flightaware.com
Wed Sep 17 19:58:14 CEST 2014


We are running varnish varnish-3.0.5 revision 1a89b1f on freebsd
(9.2-RELEASE-p10 and are seeing memory usage that does not seem to match
with what it should be using based on our configurations.  We have two
servers with 32G of physical memory and 32G of swap.  The varnishd process
grows by about 1M a second until all the physical and virtual memory is
filled, and then predictably, causes the box to crash.  We only have 6G of
malloc allocated (and confirmed with SMA.s0.g_bytes 6441093251), and
n_object 981470

We have only noticed this problem since upgrading to 3.0.5 from an earlier
3.0.x version.  I would prefer to not post our vcl publicly, but if
someone thinks it will really help diagnose/troubleshoot, we can work
something out.

Varnishd is configured as follows in rc.conf:

varnishd_storage="malloc,6G"
varnishd_opts="-p send_timeout=200 -p sess_timeout=4 -p
thread_pool_max=4000 -p thread_pool_add_delay=3 -p thread_pools=24 -p
thread_pool_min=33 -p listen_depth=4096 -p thread_pool_add_delay=2 -p
ping_interval=2 -h classic,250007 -p connect_timeout=2 -p cli_timeout=15
-p sess_workspace=262144"

varnishd_flags="-P /var/run/varnishd.pid -a ${varnishd_listen} -f
${varnishd_config} -T ${varnishd_telnet} -s ${varnishd_storage} -u
${varnishd_user} -g ${varnishd_group} ${varnishd_opts}"

—————

varnishstat -1:

client_conn          104085169       104.67 Client connections accepted
client_drop                  0         0.00 Connection dropped, no sess/wrk
client_req           171676104       172.65 Client requests received
cache_hit             80479348        80.94 Cache hits
cache_hitpass          7477423         7.52 Cache hits for pass
cache_miss            72505475        72.92 Cache misses
backend_conn          35664133        35.87 Backend conn. success
backend_unhealthy            0         0.00 Backend conn. not attempted
backend_busy            126139         0.13 Backend conn. too many
backend_fail                 0         0.00 Backend conn. failures
backend_reuse         89690334        90.20 Backend conn. reuses
backend_toolate        5596689         5.63 Backend conn. was closed
backend_recycle       95286945        95.83 Backend conn. recycles
backend_retry             9761         0.01 Backend conn. retry
fetch_head                 543         0.00 Fetch head
fetch_length          43471073        43.72 Fetch with Length
fetch_chunked         81315787        81.78 Fetch chunked
fetch_eof                    0         0.00 Fetch EOF
fetch_bad                    0         0.00 Fetch had bad headers
fetch_close             482419         0.49 Fetch wanted close
fetch_oldhttp                0         0.00 Fetch pre HTTP/1.1 closed
fetch_zero                   0         0.00 Fetch zero len
fetch_failed             42364         0.04 Fetch failed
fetch_1xx                    0         0.00 Fetch no body (1xx)
fetch_204                    0         0.00 Fetch no body (204)
fetch_304                61616         0.06 Fetch no body (304)
n_sess_mem                1150          .   N struct sess_mem
n_sess                     579          .   N struct sess
n_object                981470          .   N struct object
n_vampireobject              0          .   N unresurrected objects
n_objectcore            981914          .   N struct objectcore
n_objecthead            977110          .   N struct objecthead
n_waitinglist              622          .   N struct waitinglist
n_vbc                       54          .   N struct vbc
n_wrk                      792          .   N worker threads
n_wrk_create               792         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                    7          .   N backends
n_expired             45564349          .   N expired objects
n_lru_nuked           25923760          .   N LRU nuked objects
n_lru_moved           47547027          .   N LRU moved objects
losthdr                      6         0.00 HTTP header overflows
n_objsendfile                0         0.00 Objects sent with sendfile
n_objwrite           121715557       122.41 Objects sent with write
n_objoverflow                0         0.00 Objects overflowing workspace
s_sess               104086012       104.68 Total Sessions
s_req                171676104       172.65 Total Requests
s_pipe                       0         0.00 Total pipe
s_pass                52856380        53.16 Total pass
s_fetch              125289270       126.00 Total fetch
s_hdrbytes         64377166856     64741.92 Total header bytes
s_bodybytes       1267141154173   1274320.68 Total body bytes
sess_closed           10229836        10.29 Session Closed
sess_pipeline             8090         0.01 Session Pipeline
sess_readahead            3355         0.00 Session Read Ahead
sess_linger          163142524       164.07 Session Linger
sess_herd            170209860       171.17 Session herd
shm_records        15318912048     15405.71 SHM records
shm_writes           948277110       953.65 SHM writes
shm_flushes               4301         0.00 SHM flushes due to overflow
shm_cont                288266         0.29 SHM MTX contention
shm_cycles                6539         0.01 SHM cycles through buffer
sms_nreq                378913         0.38 SMS allocator requests
sms_nobj                     0          .   SMS outstanding allocations
sms_nbytes                   0          .   SMS outstanding bytes
sms_balloc          1053544168          .   SMS bytes allocated
sms_bfree           1053544168          .   SMS bytes freed
backend_req          125332229       126.04 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                   0         0.00 HCB Lookups without lock
hcb_lock                     0         0.00 HCB Lookups with lock
hcb_insert                   0         0.00 HCB Inserts
esi_errors                   0         0.00 ESI parse errors (unlock)
esi_warnings                 0         0.00 ESI parse warnings (unlock)
accept_fail                485         0.00 Accept failures
client_drop_late             0         0.00 Connection dropped late
uptime                  994366         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                84532076        85.01 Gzip operations
n_gunzip              89997945        90.51 Gunzip operations
sess_pipe_overflow           0          .   Dropped sessions due to
session pipe overflow
LCK.sms.creat                1         0.00 Created locks
LCK.sms.destroy              0         0.00 Destroyed locks
LCK.sms.locks          1136739         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        692749199       696.67 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                0         0.00 Created locks
LCK.hcb.destroy              0         0.00 Destroyed locks
LCK.hcb.locks                0         0.00 Lock Operations
LCK.hcb.colls                0         0.00 Collisions
LCK.hcl.creat           250007         0.25 Created locks
LCK.hcl.destroy              0         0.00 Destroyed locks
LCK.hcl.locks        319941259       321.75 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          1296332         1.30 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       104086613       104.68 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      104233722       104.82 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          3357946         3.38 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                  24         0.00 Created locks
LCK.wq.destroy                 0         0.00 Destroyed locks
LCK.wq.locks           385937676       388.12 Lock Operations
LCK.wq.colls                   0         0.00 Collisions
LCK.objhdr.creat        62749986        63.11 Created locks
LCK.objhdr.destroy      61773004        62.12 Destroyed locks
LCK.objhdr.locks       538087282       541.14 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          144950215       145.77 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           98393326        98.95 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             497050         0.50 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          145003057       145.82 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             755162         0.76 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           71328212        71.73 Lock Operations
LCK.vbe.colls                  0         0.00 Collisions
LCK.backend.creat              7         0.00 Created locks
LCK.backend.destroy            0         0.00 Destroyed locks
LCK.backend.locks      297688383       299.38 Lock Operations
LCK.backend.colls              0         0.00 Collisions
SMA.s0.c_req           191831833       192.92 Allocator requests
SMA.s0.c_fail           25986715        26.13 Allocator failures
SMA.s0.c_bytes      8510391233102   8558610.44 Bytes allocated
SMA.s0.c_freed      8503950139851   8552132.86 Bytes freed
SMA.s0.g_alloc           2003100          .   Allocations outstanding
SMA.s0.g_bytes        6441093251          .   Bytes outstanding
SMA.s0.g_space           1357693          .   Bytes available
SMA.Transient.c_req    111573947       112.21 Allocator requests
SMA.Transient.c_fail           0         0.00 Allocator failures
SMA.Transient.c_bytes 6898618916654   6937705.95 Bytes allocated
SMA.Transient.c_freed 6898613391266   6937700.40 Bytes freed
SMA.Transient.g_alloc         5373          .   Allocations outstanding
SMA.Transient.g_bytes      5525388          .   Bytes outstanding
SMA.Transient.g_space            0          .   Bytes available
VBE.backend1(<ipv4-redacted>,<ipv6-redacted>,80).vcls            1
 .   VCL references
VBE.backend1(<ipv4-redacted>,<ipv6-redacted>,80).happy18446744073709551615
         .   Happy health probes
VBE.backend2(<ipv4-redacted>,<ipv6-redacted>,80).vcls            1
 .   VCL references
VBE.backend2(<ipv4-redacted>,<ipv6-redacted>,80).happy18446744073709551615
         .   Happy health probes
VBE.backend3(<ipv4-redacted>,<ipv6-redacted>,80).vcls            1
 .   VCL references
VBE.backend3(<ipv4-redacted>,<ipv6-redacted>,80).happy18446744073709551615
         .   Happy health probes
VBE.backend4(<ipv4-redacted>,<ipv6-redacted>,80).vcls            1
 .   VCL references
VBE.backend4(<ipv4-redacted>,<ipv6-redacted>,80).happy18446744073709551615
         .   Happy health probes
VBE.backend5(<ipv4-redacted>,,80).vcls                              1
    .   VCL references
VBE.backend6(<ipv4-redacted>,,80).happy                             0
    .   Happy health probes
VBE.prod(<ipv4-redacted>,,80).vcls                                 1
   .   VCL references
VBE.prod(<ipv4-redacted>,,80).happy                                0
   .   Happy health probes
VBE.backend7(<ipv4-redacted>,<ipv6-redacted>,80).vcls           1
.   VCL references
VBE.backend7(<ipv4-redacted>,<ipv6-redacted>,80).happy            0
  .   Happy health probes



{ 
 Adam Schumacher 
 IT Operations and Security Engineer
 Flightaware 
}


-------------- next part --------------
A non-text attachment was scrubbed...
Name: smime.p7s
Type: application/pkcs7-signature
Size: 5831 bytes
Desc: not available
URL: <https://www.varnish-cache.org/lists/pipermail/varnish-misc/attachments/20140917/7efbe95d/attachment.bin>


More information about the varnish-misc mailing list