varnishstat reporting weird numbers

Hugues Alary hugues at betabrand.com
Thu Oct 31 06:50:27 CET 2013


Hi there,

I've got a problem with varnishstat and was hoping to find an answer here.

Basically, today, my varnish server (3.0.2) started acting very weirdly. I
suspect a misconfiguration on my part was at the origin of some weirdness
(like pages randomly being flushed from the cache, despite the cache being
half empty), but, our website was under low traffic (nothing Varnish can't
handle), and somehow everything went crazy:

- varnishadm would tell me that perfectly valid commands like ban.list,
vcl.list, vcl.load were wrong, returning a 105 (?) error. Preventing me
from loading a configuration without doing a varnish reload/restart.
- varnishstat would report a highly improbable high number of "duplicate
bans removed", but the rest of the reported numbers (hit, miss, etc.)
seemed pretty normal.

The panicked admin that I am decided that, if I was to restart varnish, I
should at least use the occasion to upgrade it to 3.0.4.; my dev server and
personal machine having been running 3.0.4 for the past few month with no
problems.

So I run apt-get update varnish, and get the new version.

Unfortunately, this made varnishstat even weirder. It now report 0 hits, 0
miss, 0 hit for pass. I also have seen negative numbers for n_wrk_*.

I tried restarting varnishd, made sure that varnishstat is 3.0.4,
everything is fine, my website is mostly in cache, but still varnishstat
reports what I believe are wrong numbers.

Has someone ever run into this problem?

I can provide my configuration file if needed.

Here's a varnishstat -1:

client_conn                  0         0.00 Client connections accepted
client_drop                  0         0.00 Connection dropped, no sess/wrk
client_req                   0         0.00 Client requests received
cache_hit                    0         0.00 Cache hits
cache_hitpass                0         0.00 Cache hits for pass
cache_miss                   0         0.00 Cache misses
backend_conn                 0         0.00 Backend conn. success
backend_unhealthy            0         0.00 Backend conn. not attempted
backend_busy            271072        50.69 Backend conn. too many
backend_fail                 0         0.00 Backend conn. failures
backend_reuse           560452       104.80 Backend conn. reuses
backend_toolate         656588       122.77 Backend conn. was closed
backend_recycle              0         0.00 Backend conn. recycles
backend_retry            53208         9.95 Backend conn. retry
fetch_head                9701         1.81 Fetch head
fetch_length                 0         0.00 Fetch with Length
fetch_chunked                0         0.00 Fetch chunked
fetch_eof                    0         0.00 Fetch EOF
fetch_bad                66843        12.50 Fetch had bad headers
fetch_close               8116         1.52 Fetch wanted close
fetch_oldhttp            74960        14.02 Fetch pre HTTP/1.1 closed
fetch_zero                  16         0.00 Fetch zero len
fetch_failed                12         0.00 Fetch failed
fetch_1xx                75267        14.07 Fetch no body (1xx)
fetch_204                  114         0.02 Fetch no body (204)
fetch_304                    0         0.00 Fetch no body (304)
n_sess_mem                   0          .   N struct sess_mem
n_sess                      81          .   N struct sess
n_object                     0          .   N struct object
n_vampireobject              0          .   N unresurrected objects
n_objectcore                 0          .   N struct objectcore
n_objecthead                 0          .   N struct objecthead
n_waitinglist                0          .   N struct waitinglist
n_vbc                      772          .   N struct vbc
n_wrk                      299          .   N worker threads
n_wrk_create                28         0.01 N worker threads created
n_wrk_failed             14365         2.69 N worker threads not created
n_wrk_max                    0         0.00 N worker threads limited
n_wrk_lqueue             14394         2.69 work request queue length
n_wrk_queued             14644         2.74 N queued work requests
n_wrk_drop                  29         0.01 N dropped work requests
n_backend                    1          .   N backends
n_expired                   29          .   N expired objects
n_lru_nuked                485          .   N LRU nuked objects
n_lru_moved                  0          .   N LRU moved objects
losthdr                      0         0.00 HTTP header overflows
n_objsendfile                0         0.00 Objects sent with sendfile
n_objwrite                2751         0.51 Objects sent with write
n_objoverflow                0         0.00 Objects overflowing workspace
s_sess                       1         0.00 Total Sessions
s_req                    38843         7.26 Total Requests
s_pipe                       0         0.00 Total pipe
s_pass                  530752        99.24 Total pass
s_fetch                     64         0.01 Total fetch
s_hdrbytes                   0         0.00 Total header bytes
s_bodybytes             689741       128.97 Total body bytes
sess_closed                  0         0.00 Session Closed
sess_pipeline           271072        50.69 Session Pipeline
sess_readahead          560452       104.80 Session Read Ahead
sess_linger                255         0.05 Session Linger
sess_herd                23065         4.31 Session herd
shm_records              76246        14.26 SHM records
shm_writes           203311427     38016.35 SHM writes
shm_flushes        34338009106   6420719.73 SHM flushes due to overflow
shm_cont                 26666         4.99 SHM MTX contention
shm_cycles                1234         0.23 SHM cycles through buffer
sms_nreq                   235         0.04 SMS allocator requests
sms_nobj                541285          .   SMS outstanding allocations
sms_nbytes              566363          .   SMS outstanding bytes
sms_balloc            30696332          .   SMS bytes allocated
sms_bfree              2279693          .   SMS bytes freed
backend_req                  0         0.00 Backend requests made
n_vcl                     2756         0.52 N vcl total
n_vcl_avail                 13         0.00 N vcl available
n_vcl_discard             1447         0.27 N vcl discarded
n_ban                        0          .   N total active bans
n_ban_add                    0         0.00 N new bans added
n_ban_retire           1883994       352.28 N old bans deleted
n_ban_obj_test         1883994       352.28 N objects tested
n_ban_re_test            76246        14.26 N regexps tested against
n_ban_dups                   6         0.00 N duplicate bans removed
hcb_nolock                   6         0.00 HCB Lookups without lock
hcb_lock                     0         0.00 HCB Lookups with lock
hcb_insert                  11         0.00 HCB Inserts
esi_errors                   6         0.00 ESI parse errors (unlock)
esi_warnings              6723         1.26 ESI parse warnings (unlock)
accept_fail               6712         1.26 Accept failures
client_drop_late       2054111       384.09 Connection dropped late
uptime                23573960      4408.00 Client uptime
dir_dns_lookups           5348         1.00 DNS director lookups
dir_dns_failed          709796       132.72 DNS director failed lookups
dir_dns_hit              50845         9.51 DNS director cached lookups hit
dir_dns_cache_full       50844         9.51 DNS director full dnscache
vmods                        0          .   Loaded VMODs
n_gzip                       0         0.00 Gzip operations
n_gunzip                     0         0.00 Gunzip operations
LCK.sms.creat                0         0.00 Created locks
LCK.sms.destroy              0         0.00 Destroyed locks
LCK.sms.locks                0         0.00 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                0         0.00 Created locks
LCK.sma.destroy              0         0.00 Destroyed locks
LCK.sma.locks                0         0.00 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                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                0         0.00 Created locks
LCK.vcl.destroy              0         0.00 Destroyed locks
LCK.vcl.locks                0         0.00 Lock Operations
LCK.vcl.colls                0         0.00 Collisions
LCK.stat.creat               0         0.00 Created locks
LCK.stat.destroy             0         0.00 Destroyed locks
LCK.stat.locks               0         0.00 Lock Operations
LCK.stat.colls               0         0.00 Collisions
LCK.sessmem.creat            0         0.00 Created locks
LCK.sessmem.destroy            0         0.00 Destroyed locks
LCK.sessmem.locks              0         0.00 Lock Operations
LCK.sessmem.colls              0         0.00 Collisions
LCK.wstat.creat                0         0.00 Created locks
LCK.wstat.destroy              0         0.00 Destroyed locks
LCK.wstat.locks                0         0.00 Lock Operations
LCK.wstat.colls                0         0.00 Collisions
LCK.herder.creat               0         0.00 Created locks
LCK.herder.destroy             0         0.00 Destroyed locks
LCK.herder.locks               0         0.00 Lock Operations
LCK.herder.colls               0         0.00 Collisions
LCK.wq.creat                   0         0.00 Created locks
LCK.wq.destroy                 0         0.00 Destroyed locks
LCK.wq.locks                   0         0.00 Lock Operations
LCK.wq.colls                   0         0.00 Collisions
LCK.objhdr.creat               0         0.00 Created locks
LCK.objhdr.destroy             0         0.00 Destroyed locks
LCK.objhdr.locks               0         0.00 Lock Operations
LCK.objhdr.colls               0         0.00 Collisions
LCK.exp.creat                  0         0.00 Created locks
LCK.exp.destroy                0         0.00 Destroyed locks
LCK.exp.locks                  0         0.00 Lock Operations
LCK.exp.colls                  0         0.00 Collisions
LCK.lru.creat                  0         0.00 Created locks
LCK.lru.destroy                0         0.00 Destroyed locks
LCK.lru.locks                  0         0.00 Lock Operations
LCK.lru.colls                  0         0.00 Collisions
LCK.cli.creat                  0         0.00 Created locks
LCK.cli.destroy                0         0.00 Destroyed locks
LCK.cli.locks                  0         0.00 Lock Operations
LCK.cli.colls                  0         0.00 Collisions
LCK.ban.creat                  0         0.00 Created locks
LCK.ban.destroy                0         0.00 Destroyed locks
LCK.ban.locks                  0         0.00 Lock Operations
LCK.ban.colls                  0         0.00 Collisions
LCK.vbp.creat                  0         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                  0         0.00 Created locks
LCK.vbe.destroy                0         0.00 Destroyed locks
LCK.vbe.locks                  0         0.00 Lock Operations
LCK.vbe.colls                  0         0.00 Collisions
LCK.backend.creat              0         0.00 Created locks
LCK.backend.destroy            0         0.00 Destroyed locks
LCK.backend.locks              0         0.00 Lock Operations
LCK.backend.colls              0         0.00 Collisions
SMA.memory.c_req               0         0.00 Allocator requests
SMA.memory.c_fail              0         0.00 Allocator failures
SMA.memory.c_bytes             0         0.00 Bytes allocated
SMA.memory.c_freed             0         0.00 Bytes freed
SMA.memory.g_alloc             0          .   Allocations outstanding
SMA.memory.g_bytes             0          .   Bytes outstanding
SMA.memory.g_space             0          .   Bytes available
SMA.Transient.c_req            0         0.00 Allocator requests
SMA.Transient.c_fail           0         0.00 Allocator failures
SMA.Transient.c_bytes            0         0.00 Bytes allocated
SMA.Transient.c_freed            0         0.00 Bytes freed
SMA.Transient.g_alloc            0          .   Allocations outstanding
SMA.Transient.g_bytes            0          .   Bytes outstanding
SMA.Transient.g_space            0          .   Bytes available
VBE.default(127.0.0.1,,8080).vcls            0          .   VCL references
VBE.default(127.0.0.1,,8080).happy           0          .   Happy health
probes


Thanks for any help!

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


More information about the varnish-misc mailing list