logging bug for rpz at load-time?

[Phil Mayers]

On 03/09/15 15:14, Mukund Sivaraman wrote:

> The numbers are overall counts for that view, after the contents of that
> policy zone have been loaded. Cumulatively, they should match the number
> of records in your policy zones (named starts with empty RPZ state).

In that case, those counts are absolutely not correct (see below)

>> This is on 9.10.2-P4
>
> If these numbers (for the view) don't match up, can you try reproducing
> this with 9.10.3-rc1 and let us know what you get? There have been some
> bugfixes since 9.10.2.

It'll be a couple of weeks before I could look at that - my availability 
is poor for the next while.

> How many policy zones do you have? If you can, please send us your named
> configuration and the expected number of RRs that you intend to see.

I'm a tiny bit uncomfortable exposing the detailed config here given 
what it does.

There are three zones, and the config basically looks like this:

   response-policy {

     # Local black/whitelist - currently 486 RRs
     zone "rpz.<local>";

     # Commercial feed #1 - approx 600k entries
     zone "rpz.<feed1>" policy ...;

     # Commercial feed #2 - approx 750 entries
     zone "rpz.<feed2>";
   };

I restarted named to get it to log them, and I saw:

(re)loading policy zone 'rpz.<feed2>' changed from 0 to 5458 qname
(re)loading policy zone 'rpz.<local>' changed from 5458 to 25032 qname
(re)loading policy zone 'rpz.<feed1>' changed from 25032 to 1216066 qname

I then immediately restarted it again, and coming up with the *same* 
zone contents, a few seconds later, it logged:

(re)loading policy zone 'rpz.<feed2>' changed from 0 to 0 qname
(re)loading policy zone 'rpz.<local>' changed from 0 to 19089 qname
(re)loading policy zone 'rpz.<feed1>' changed from 19089 to 1216066 qname

So they're basically totally fictitious - is it maybe logging the counts 
while the following zone(s) are loading in i.e. some concurrency thing?

Cheers,
Phil