[Varnish] #1635: Completed bans keep accumulating

[Varnish]

#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