I have varnish setup with 2 backend servers with a round-robin director.
The 2 backends are showing up in varnishstat and varnishadm as healthy.
varnishadm output:
Backend name Admin Probe
boot.app1 probe Healthy 5/5
boot.app2 probe Healthy 5/5
VCL Configuration:
probe ping {
.interval = 5s;
.timeout = 1s;
.threshold = 3;
.window = 5;
.url = "/ping";
}
backend app1 {
.host = "app-1.example.com";
.port = "80";
.probe = ping;
}
backend app2 {
.host = "app-2.example.com";
.port = "80";
.probe = ping;
}
new application_servers = directors.round_robin();
application_servers.add_backend(app1);
application_servers.add_backend(app2);
set req.backend_hint = application_servers;
varnishstat output:
VBE.boot.app1.happy ffffffffff VVVVVVVVVVVVVVVVVVVVVVVV
VBE.boot.app1.bereq_hdrbytes 66.17K 0.00 91.00 0.00 0.00 0.00
VBE.boot.app1.beresp_hdrbytes 76.72K 0.00 106.00 0.00 0.00 0.00
VBE.boot.app1.beresp_bodybytes 11.91M 0.00 16.50K 0.00 0.00 0.00
VBE.boot.app1.conn 251 0.00 . 251.00 251.00 251.00
VBE.boot.app1.req 251 0.00 . 0.00 0.00 0.00
VBE.boot.app2.happy ffffffffff VVVVVVVVVVVVVVVVVVVVVVVV
You can see from the varnishstat command that traffic appears to only be sent to the first server in the round-robin configuration. There's no other lines for the app2 server other than .happy
Any thoughts on what would be causing the director to pick the first server every time?
MAIN.uptime 218639 1.00 Child process uptime
MAIN.sess_conn 5253150 24.03 Sessions accepted
MAIN.sess_drop 0 0.00 Sessions dropped
MAIN.sess_fail 0 0.00 Session accept failures
MAIN.client_req_400 0 0.00 Client requests received, subject to 400 errors
MAIN.client_req_417 0 0.00 Client requests received, subject to 417 errors
MAIN.client_req 1174495 5.37 Good client requests received
MAIN.cache_hit 61 0.00 Cache hits
MAIN.cache_hitpass 395 0.00 Cache hits for pass
MAIN.cache_miss 1927 0.01 Cache misses
MAIN.backend_conn 0 0.00 Backend conn. success
MAIN.backend_unhealthy 0 0.00 Backend conn. not attempted
MAIN.backend_busy 0 0.00 Backend conn. too many
MAIN.backend_fail 0 0.00 Backend conn. failures
MAIN.backend_reuse 7720 0.04 Backend conn. reuses
MAIN.backend_recycle 8926 0.04 Backend conn. recycles
MAIN.backend_retry 0 0.00 Backend conn. retry
MAIN.fetch_head 0 0.00 Fetch no body (HEAD)
MAIN.fetch_length 1350 0.01 Fetch with Length
MAIN.fetch_chunked 7572 0.03 Fetch chunked
MAIN.fetch_eof 3 0.00 Fetch EOF
MAIN.fetch_bad 0 0.00 Fetch bad T-E
MAIN.fetch_none 0 0.00 Fetch no body
MAIN.fetch_1xx 0 0.00 Fetch no body (1xx)
MAIN.fetch_204 0 0.00 Fetch no body (204)
MAIN.fetch_304 27 0.00 Fetch no body (304)
MAIN.fetch_failed 0 0.00 Fetch failed (all causes)
MAIN.fetch_no_thread 0 0.00 Fetch failed (no thread)
MAIN.pools 2 . Number of thread pools
MAIN.threads 20 . Total number of threads
MAIN.threads_limited 0 0.00 Threads hit max
MAIN.threads_created 1377 0.01 Threads created
MAIN.threads_destroyed 1357 0.01 Threads destroyed
MAIN.threads_failed 0 0.00 Thread creation failed
MAIN.thread_queue_len 0 . Length of session queue
MAIN.busy_sleep 3 0.00 Number of requests sent to sleep on busy objhdr
MAIN.busy_wakeup 3 0.00 Number of requests woken after sleep on busy objhdr
MAIN.busy_killed 0 0.00 Number of requests killed after sleep on busy objhdr
MAIN.sess_queued 1728 0.01 Sessions queued for thread
MAIN.sess_dropped 0 0.00 Sessions dropped for thread
MAIN.n_object 135 . object structs made
MAIN.n_vampireobject 0 . unresurrected objects
MAIN.n_objectcore 141 . objectcore structs made
MAIN.n_objecthead 146 . objecthead structs made
MAIN.n_waitinglist 17 . waitinglist structs made
MAIN.n_backend 6 . Number of backends
MAIN.n_expired 840 . Number of expired objects
MAIN.n_lru_nuked 0 . Number of LRU nuked objects
MAIN.n_lru_moved 52 . Number of LRU moved objects
MAIN.losthdr 0 0.00 HTTP header overflows
MAIN.s_sess 5253150 24.03 Total sessions seen
MAIN.s_req 1174495 5.37 Total requests seen
MAIN.s_pipe 0 0.00 Total pipe sessions seen
MAIN.s_pass 7025 0.03 Total pass-ed requests seen
MAIN.s_fetch 8952 0.04 Total backend fetches initiated
MAIN.s_synth 1165482 5.33 Total synthethic responses made
MAIN.s_req_hdrbytes 58007743 265.31 Request header bytes
MAIN.s_req_bodybytes 8324 0.04 Request body bytes
MAIN.s_resp_hdrbytes 250174363 1144.23 Response header bytes
MAIN.s_resp_bodybytes 658785662 3013.12 Response body bytes
MAIN.s_pipe_hdrbytes 0 0.00 Pipe request header bytes
MAIN.s_pipe_in 0 0.00 Piped bytes from client
MAIN.s_pipe_out 0 0.00 Piped bytes to client
MAIN.sess_closed 1170177 5.35 Session Closed
MAIN.sess_closed_err 5244623 23.99 Session Closed with error
MAIN.sess_readahead 0 0.00 Session Read Ahead
MAIN.sess_herd 3208 0.01 Session herd
MAIN.sc_rem_close 3518 0.02 Session OK REM_CLOSE
MAIN.sc_req_close 0 0.00 Session OK REQ_CLOSE
MAIN.sc_req_http10 1165458 5.33 Session Err REQ_HTTP10
MAIN.sc_rx_bad 0 0.00 Session Err RX_BAD
MAIN.sc_rx_body 0 0.00 Session Err RX_BODY
MAIN.sc_rx_junk 4079015 18.66 Session Err RX_JUNK
MAIN.sc_rx_overflow 0 0.00 Session Err RX_OVERFLOW
MAIN.sc_rx_timeout 276 0.00 Session Err RX_TIMEOUT
MAIN.sc_tx_pipe 0 0.00 Session OK TX_PIPE
MAIN.sc_tx_error 0 0.00 Session Err TX_ERROR
MAIN.sc_tx_eof 0 0.00 Session OK TX_EOF
MAIN.sc_resp_close 4688 0.02 Session OK RESP_CLOSE
MAIN.sc_overload 0 0.00 Session Err OVERLOAD
MAIN.sc_pipe_overflow 0 0.00 Session Err PIPE_OVERFLOW
MAIN.sc_range_short 0 0.00 Session Err RANGE_SHORT
MAIN.shm_records 92391706 422.58 SHM records
MAIN.shm_writes 24787122 113.37 SHM writes
MAIN.shm_flushes 4278 0.02 SHM flushes due to overflow
MAIN.shm_cont 72956 0.33 SHM MTX contention
MAIN.shm_cycles 30 0.00 SHM cycles through buffer
MAIN.backend_req 8952 0.04 Backend requests made
MAIN.n_vcl 3 0.00 Number of loaded VCLs in total
MAIN.n_vcl_avail 3 0.00 Number of VCLs available
MAIN.n_vcl_discard 0 0.00 Number of discarded VCLs
MAIN.bans 1 . Count of bans
MAIN.bans_completed 1 . Number of bans marked 'completed'
MAIN.bans_obj 0 . Number of bans using obj.*
MAIN.bans_req 0 . Number of bans using req.*
MAIN.bans_added 1 0.00 Bans added
MAIN.bans_deleted 0 0.00 Bans deleted
MAIN.bans_tested 0 0.00 Bans tested against objects (lookup)
MAIN.bans_obj_killed 0 0.00 Objects killed by bans (lookup)
MAIN.bans_lurker_tested 0 0.00 Bans tested against objects (lurker)
MAIN.bans_tests_tested 0 0.00 Ban tests tested against objects (lookup)
MAIN.bans_lurker_tests_tested 0 0.00 Ban tests tested against objects (lurker)
MAIN.bans_lurker_obj_killed 0 0.00 Objects killed by bans (lurker)
MAIN.bans_dups 0 0.00 Bans superseded by other bans
MAIN.bans_lurker_contention 0 0.00 Lurker gave way for lookup
MAIN.bans_persisted_bytes 16 . Bytes used by the persisted ban lists
MAIN.bans_persisted_fragmentation 0 . Extra bytes in persisted ban lists due to fragmentation
MAIN.n_purges 0 . Number of purge operations executed
MAIN.n_obj_purged 0 . Number of purged objects
MAIN.exp_mailed 2879 0.01 Number of objects mailed to expiry thread
MAIN.exp_received 2879 0.01 Number of objects received by expiry thread
MAIN.hcb_nolock 2383 0.01 HCB Lookups without lock
MAIN.hcb_lock 975 0.00 HCB Lookups with lock
MAIN.hcb_insert 975 0.00 HCB Inserts
MAIN.esi_errors 0 0.00 ESI parse errors (unlock)
MAIN.esi_warnings 0 0.00 ESI parse warnings (unlock)
MAIN.vmods 2 . Loaded VMODs
MAIN.n_gzip 0 0.00 Gzip operations
MAIN.n_gunzip 2945 0.01 Gunzip operations
MAIN.vsm_free 972480 . Free VSM space
MAIN.vsm_used 83961104 . Used VSM space
MAIN.vsm_cooling 1024 . Cooling VSM space
MAIN.vsm_overflow 0 . Overflow VSM space
MAIN.vsm_overflowed 0 0.00 Overflowed VSM space
MGT.uptime 218640 1.00 Management process uptime
MGT.child_start 1 0.00 Child process started
MGT.child_exit 0 0.00 Child process normal exit
MGT.child_stop 0 0.00 Child process unexpected exit
MGT.child_died 0 0.00 Child process died (signal)
MGT.child_dump 0 0.00 Child process core dumped
MGT.child_panic 0 0.00 Child process panic
MEMPOOL.busyobj.live 0 . In use
MEMPOOL.busyobj.pool 10 . In Pool
MEMPOOL.busyobj.sz_wanted 65536 . Size requested
MEMPOOL.busyobj.sz_actual 65504 . Size allocated
MEMPOOL.busyobj.allocs 8952 0.04 Allocations
MEMPOOL.busyobj.frees 8952 0.04 Frees
MEMPOOL.busyobj.recycle 8934 0.04 Recycled from pool
MEMPOOL.busyobj.timeout 2477 0.01 Timed out from pool
MEMPOOL.busyobj.toosmall 0 0.00 Too small to recycle
MEMPOOL.busyobj.surplus 0 0.00 Too many for pool
MEMPOOL.busyobj.randry 18 0.00 Pool ran dry
MEMPOOL.req0.live 0 . In use
MEMPOOL.req0.pool 10 . In Pool
MEMPOOL.req0.sz_wanted 65536 . Size requested
MEMPOOL.req0.sz_actual 65504 . Size allocated
MEMPOOL.req0.allocs 2622296 11.99 Allocations
MEMPOOL.req0.frees 2622296 11.99 Frees
MEMPOOL.req0.recycle 2622295 11.99 Recycled from pool
MEMPOOL.req0.timeout 1604 0.01 Timed out from pool
MEMPOOL.req0.toosmall 0 0.00 Too small to recycle
MEMPOOL.req0.surplus 0 0.00 Too many for pool
MEMPOOL.req0.randry 1 0.00 Pool ran dry
MEMPOOL.sess0.live 0 . In use
MEMPOOL.sess0.pool 10 . In Pool
MEMPOOL.sess0.sz_wanted 512 . Size requested
MEMPOOL.sess0.sz_actual 480 . Size allocated
MEMPOOL.sess0.allocs 2620824 11.99 Allocations
MEMPOOL.sess0.frees 2620824 11.99 Frees
MEMPOOL.sess0.recycle 2620823 11.99 Recycled from pool
MEMPOOL.sess0.timeout 2001 0.01 Timed out from pool
MEMPOOL.sess0.toosmall 0 0.00 Too small to recycle
MEMPOOL.sess0.surplus 0 0.00 Too many for pool
MEMPOOL.sess0.randry 1 0.00 Pool ran dry
MEMPOOL.req1.live 0 . In use
MEMPOOL.req1.pool 10 . In Pool
MEMPOOL.req1.sz_wanted 65536 . Size requested
MEMPOOL.req1.sz_actual 65504 . Size allocated
MEMPOOL.req1.allocs 2633786 12.05 Allocations
MEMPOOL.req1.frees 2633786 12.05 Frees
MEMPOOL.req1.recycle 2633785 12.05 Recycled from pool
MEMPOOL.req1.timeout 1589 0.01 Timed out from pool
MEMPOOL.req1.toosmall 0 0.00 Too small to recycle
MEMPOOL.req1.surplus 0 0.00 Too many for pool
MEMPOOL.req1.randry 1 0.00 Pool ran dry
MEMPOOL.sess1.live 0 . In use
MEMPOOL.sess1.pool 10 . In Pool
MEMPOOL.sess1.sz_wanted 512 . Size requested
MEMPOOL.sess1.sz_actual 480 . Size allocated
MEMPOOL.sess1.allocs 2632326 12.04 Allocations
MEMPOOL.sess1.frees 2632326 12.04 Frees
MEMPOOL.sess1.recycle 2632325 12.04 Recycled from pool
MEMPOOL.sess1.timeout 1908 0.01 Timed out from pool
MEMPOOL.sess1.toosmall 0 0.00 Too small to recycle
MEMPOOL.sess1.surplus 0 0.00 Too many for pool
MEMPOOL.sess1.randry 1 0.00 Pool ran dry
SMA.s0.c_req 93 0.00 Allocator requests
SMA.s0.c_fail 0 0.00 Allocator failures
SMA.s0.c_bytes 905611 4.14 Bytes allocated
SMA.s0.c_freed 849277 3.88 Bytes freed
SMA.s0.g_alloc 7 . Allocations outstanding
SMA.s0.g_bytes 56334 . Bytes outstanding
SMA.s0.g_space 6442394610 . Bytes available
SMA.Transient.c_req 2363316 10.81 Allocator requests
SMA.Transient.c_fail 0 0.00 Allocator failures
SMA.Transient.c_bytes 2083208664 9528.07 Bytes allocated
SMA.Transient.c_freed 2083145488 9527.79 Bytes freed
SMA.Transient.g_alloc 132 . Allocations outstanding
SMA.Transient.g_bytes 63176 . Bytes outstanding
SMA.Transient.g_space 0 . Bytes available
VBE.58b9f33d-bb8c-4540-ab9e-73da4e8c1cf9.app1.happy 18446744073709551615 . Happy health probes
VBE.58b9f33d-bb8c-4540-ab9e-73da4e8c1cf9.app1.bereq_hdrbytes 1944414 8.89 Request header bytes
VBE.58b9f33d-bb8c-4540-ab9e-73da4e8c1cf9.app1.bereq_bodybytes 8324 0.04 Request body bytes
VBE.58b9f33d-bb8c-4540-ab9e-73da4e8c1cf9.app1.beresp_hdrbytes 1608040 7.35 Response header bytes
VBE.58b9f33d-bb8c-4540-ab9e-73da4e8c1cf9.app1.beresp_bodybytes 154396823 706.17 Response body bytes
VBE.58b9f33d-bb8c-4540-ab9e-73da4e8c1cf9.app1.pipe_hdrbytes 0 0.00 Pipe request header bytes
VBE.58b9f33d-bb8c-4540-ab9e-73da4e8c1cf9.app1.pipe_out 0 0.00 Piped bytes to backend
VBE.58b9f33d-bb8c-4540-ab9e-73da4e8c1cf9.app1.pipe_in 0 0.00 Piped bytes from backend
VBE.58b9f33d-bb8c-4540-ab9e-73da4e8c1cf9.app1.conn 4297 . Concurrent connections to backend
VBE.58b9f33d-bb8c-4540-ab9e-73da4e8c1cf9.app1.req 4297 0.02 Backend requests sent
VBE.58b9f33d-bb8c-4540-ab9e-73da4e8c1cf9.app2.happy 18446744073709551615 . Happy health probes
VBE.58b9f33d-bb8c-4540-ab9e-73da4e8c1cf9.app2.bereq_hdrbytes 0 0.00 Request header bytes
VBE.58b9f33d-bb8c-4540-ab9e-73da4e8c1cf9.app2.bereq_bodybytes 0 0.00 Request body bytes
VBE.58b9f33d-bb8c-4540-ab9e-73da4e8c1cf9.app2.beresp_hdrbytes 0 0.00 Response header bytes
VBE.58b9f33d-bb8c-4540-ab9e-73da4e8c1cf9.app2.beresp_bodybytes 0 0.00 Response body bytes
VBE.58b9f33d-bb8c-4540-ab9e-73da4e8c1cf9.app2.pipe_hdrbytes 0 0.00 Pipe request header bytes
VBE.58b9f33d-bb8c-4540-ab9e-73da4e8c1cf9.app2.pipe_out 0 0.00 Piped bytes to backend
VBE.58b9f33d-bb8c-4540-ab9e-73da4e8c1cf9.app2.pipe_in 0 0.00 Piped bytes from backend
VBE.58b9f33d-bb8c-4540-ab9e-73da4e8c1cf9.app2.conn 0 . Concurrent connections to backend
VBE.58b9f33d-bb8c-4540-ab9e-73da4e8c1cf9.app2.req 0 0.00 Backend requests sent
LCK.backend.creat 7 0.00 Created locks
LCK.backend.destroy 0 0.00 Destroyed locks
LCK.backend.locks 194025 0.89 Lock Operations
LCK.backend_tcp.creat 2 0.00 Created locks
LCK.backend_tcp.destroy 0 0.00 Destroyed locks
LCK.backend_tcp.locks 34549 0.16 Lock Operations
LCK.ban.creat 1 0.00 Created locks
LCK.ban.destroy 0 0.00 Destroyed locks
LCK.ban.locks 1193862 5.46 Lock Operations
LCK.busyobj.creat 8951 0.04 Created locks
LCK.busyobj.destroy 8952 0.04 Destroyed locks
LCK.busyobj.locks 227907 1.04 Lock Operations
LCK.cli.creat 1 0.00 Created locks
LCK.cli.destroy 0 0.00 Destroyed locks
LCK.cli.locks 72890 0.33 Lock Operations
LCK.exp.creat 1 0.00 Created locks
LCK.exp.destroy 0 0.00 Destroyed locks
LCK.exp.locks 17964 0.08 Lock Operations
LCK.hcb.creat 1 0.00 Created locks
LCK.hcb.destroy 0 0.00 Destroyed locks
LCK.hcb.locks 3030 0.01 Lock Operations
LCK.lru.creat 2 0.00 Created locks
LCK.lru.destroy 0 0.00 Destroyed locks
LCK.lru.locks 6675 0.03 Lock Operations
LCK.mempool.creat 5 0.00 Created locks
LCK.mempool.destroy 0 0.00 Destroyed locks
LCK.mempool.locks 22011020 100.67 Lock Operations
LCK.objhdr.creat 1094 0.01 Created locks
LCK.objhdr.destroy 947 0.00 Destroyed locks
LCK.objhdr.locks 4780984 21.87 Lock Operations
LCK.pipestat.creat 1 0.00 Created locks
LCK.pipestat.destroy 0 0.00 Destroyed locks
LCK.pipestat.locks 0 0.00 Lock Operations
LCK.sess.creat 5250338 24.01 Created locks
LCK.sess.destroy 5252842 24.03 Destroyed locks
LCK.sess.locks 11 0.00 Lock Operations
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.vbe.creat 1 0.00 Created locks
LCK.vbe.destroy 0 0.00 Destroyed locks
LCK.vbe.locks 72885 0.33 Lock Operations
LCK.vcapace.creat 1 0.00 Created locks
LCK.vcapace.destroy 0 0.00 Destroyed locks
LCK.vcapace.locks 0 0.00 Lock Operations
LCK.vcl.creat 1 0.00 Created locks
LCK.vcl.destroy 0 0.00 Destroyed locks
LCK.vcl.locks 33732 0.15 Lock Operations
LCK.vxid.creat 1 0.00 Created locks
LCK.vxid.destroy 0 0.00 Destroyed locks
LCK.vxid.locks 1348 0.01 Lock Operations
LCK.waiter.creat 2 0.00 Created locks
LCK.waiter.destroy 0 0.00 Destroyed locks
LCK.waiter.locks 43236 0.20 Lock Operations
LCK.wq.creat 3 0.00 Created locks
LCK.wq.destroy 0 0.00 Destroyed locks
LCK.wq.locks 16545779 75.68 Lock Operations
LCK.wstat.creat 1 0.00 Created locks
LCK.wstat.destroy 0 0.00 Destroyed locks
LCK.wstat.locks 5362050 24.52 Lock Operations
LCK.sma.creat 2 0.00 Created locks
LCK.sma.destroy 0 0.00 Destroyed locks
LCK.sma.locks 4726679 21.62 Lock Operations
Found that the issue was related to the puppet module for deploying varnish.
The puppet module wasn't including the relevant template in the vcl file.
I've submitted a pull request to GitHub to fix this