#1635: Completed bans keep accumulating
--------------------+----------------------
Reporter: Sesse | Type: defect
Status: new | Priority: normal
Milestone: | Component: varnishd
Version: trunk | Severity: normal
Keywords: lurker |
--------------------+----------------------
Hi,
I have a site where almost every backend response (vcl_backend_response)
produces a new ban, of the form:
ban ( "obj.http.x-analysis == 1 && obj.http.x-rglm != " +
beresp.http.x-rglm );
Pretty soon, these bans go into completed state. However, for some reason
the ban lurker doesn't manage to delete them, even though there are no
req.* bans. This seems to go on and on until I have hundreds of thousands
of bans, and BAN_Insert and ban_lurker both take significant amounts of
CPU time. Making the ban lurker wake up more often does not seem to help
anything; the ban count still goes up and never seems to go down (at all).
If I stop the backend entirely, so no requests ever go through, it seems
to actually reduce the count after a while. Start it again, and the count
increases. It's 100% reproducible for me.
Relevant parts of varnishstat -1:
MAIN.bans 507 . Count of bans
MAIN.bans_completed 505 . Number of bans marked
'completed'
MAIN.bans_obj 507 . Number of bans using
obj.*
MAIN.bans_req 0 . Number of bans using
req.*
MAIN.bans_added 25714 0.18 Bans added
MAIN.bans_deleted 25207 0.18 Bans deleted
MAIN.bans_tested 19528 0.14 Bans tested against
objects (lookup)
MAIN.bans_obj_killed 8168 0.06 Objects killed by bans
(lookup)
MAIN.bans_lurker_tested 20704629 147.19 Bans tested against
objects (lurker)
MAIN.bans_tests_tested 67431 0.48 Ban tests tested against
objects (lookup)
MAIN.bans_lurker_tests_tested 20721896 147.31 Ban tests tested
against objects (lurker)
MAIN.bans_lurker_obj_killed 13909 0.10 Objects killed by
bans (lurker)
MAIN.bans_dups 15323 0.11 Bans superseded by
other bans
MAIN.bans_lurker_contention 0 0.00 Lurker gave way
for lookup
MAIN.bans_persisted_bytes 1619932 . Bytes used by the
persisted ban lists
MAIN.bans_persisted_fragmentation 1613241 . Extra bytes in
persisted ban lists due to
fragmentation
Relevant parts of my VCL:
http://git.sesse.net/?p=remoteglot;a=blob;f=default.vcl;h=38631cb4f1d3c6f399dd4fb1378dec993339aa32;hb=HEAD
This is Varnish from git, 7746e30e2c53cf55f0f2525bb3f49c9ee83e9611.
--
Ticket URL: <https://www.varnish-cache.org/trac/ticket/1635>
Varnish <https://varnish-cache.org/>
The Varnish HTTP Accelerator
_______________________________________________
varnish-bugs mailing list
varnish-bugs@varnish-cache.org
https://www.varnish-cache.org/lists/mailman/listinfo/varnish-bugs
--------------------+----------------------
Reporter: Sesse | Type: defect
Status: new | Priority: normal
Milestone: | Component: varnishd
Version: trunk | Severity: normal
Keywords: lurker |
--------------------+----------------------
Hi,
I have a site where almost every backend response (vcl_backend_response)
produces a new ban, of the form:
ban ( "obj.http.x-analysis == 1 && obj.http.x-rglm != " +
beresp.http.x-rglm );
Pretty soon, these bans go into completed state. However, for some reason
the ban lurker doesn't manage to delete them, even though there are no
req.* bans. This seems to go on and on until I have hundreds of thousands
of bans, and BAN_Insert and ban_lurker both take significant amounts of
CPU time. Making the ban lurker wake up more often does not seem to help
anything; the ban count still goes up and never seems to go down (at all).
If I stop the backend entirely, so no requests ever go through, it seems
to actually reduce the count after a while. Start it again, and the count
increases. It's 100% reproducible for me.
Relevant parts of varnishstat -1:
MAIN.bans 507 . Count of bans
MAIN.bans_completed 505 . Number of bans marked
'completed'
MAIN.bans_obj 507 . Number of bans using
obj.*
MAIN.bans_req 0 . Number of bans using
req.*
MAIN.bans_added 25714 0.18 Bans added
MAIN.bans_deleted 25207 0.18 Bans deleted
MAIN.bans_tested 19528 0.14 Bans tested against
objects (lookup)
MAIN.bans_obj_killed 8168 0.06 Objects killed by bans
(lookup)
MAIN.bans_lurker_tested 20704629 147.19 Bans tested against
objects (lurker)
MAIN.bans_tests_tested 67431 0.48 Ban tests tested against
objects (lookup)
MAIN.bans_lurker_tests_tested 20721896 147.31 Ban tests tested
against objects (lurker)
MAIN.bans_lurker_obj_killed 13909 0.10 Objects killed by
bans (lurker)
MAIN.bans_dups 15323 0.11 Bans superseded by
other bans
MAIN.bans_lurker_contention 0 0.00 Lurker gave way
for lookup
MAIN.bans_persisted_bytes 1619932 . Bytes used by the
persisted ban lists
MAIN.bans_persisted_fragmentation 1613241 . Extra bytes in
persisted ban lists due to
fragmentation
Relevant parts of my VCL:
http://git.sesse.net/?p=remoteglot;a=blob;f=default.vcl;h=38631cb4f1d3c6f399dd4fb1378dec993339aa32;hb=HEAD
This is Varnish from git, 7746e30e2c53cf55f0f2525bb3f49c9ee83e9611.
--
Ticket URL: <https://www.varnish-cache.org/trac/ticket/1635>
Varnish <https://varnish-cache.org/>
The Varnish HTTP Accelerator
_______________________________________________
varnish-bugs mailing list
varnish-bugs@varnish-cache.org
https://www.varnish-cache.org/lists/mailman/listinfo/varnish-bugs