Latest BIND: Error "rpz_rewrite_name: mismatched summary data; continuing"

Previous Topic Next Topic
 
classic Classic list List threaded Threaded
10 messages Options
Reply | Threaded
Open this post in threaded view
|

Latest BIND: Error "rpz_rewrite_name: mismatched summary data; continuing"

Tom Tom

Hi list

Using self-compiled latest bind (9.10.4-P2):

I have a bind-setup with activated response-policy-zones. For each client-forward-query, which has a valid dns-response, I got an error in the client-log (for NXDOMAIN-Reponses, I didn't have such errors... ex. "dig @nameserver aasledkfjasdlkfjsadlf.asdlfkjsadlfkjasdjflk"):

- 30-Aug-2016 06:43:51.722 client: error: query client=0x7f1074112200 thread=0x7f107a8a7700 (google.com/A): rpz_rewrite_name: mismatched summary data; continuing

- 30-Aug-2016 06:46:19.312 client: error: query client=0x7f10741614e0 thread=0x7f107b0a8700 (yahoo.com/A): rpz_rewrite_name: mismatched summary data; continuing

...
...

The client receives the right response, dns-rpz is also working, but I'm suspicious about the errors mentioned above. Any hints?
Thanks a lot.

Kind regards,
Tom

_______________________________________________
Please visit https://lists.isc.org/mailman/listinfo/bind-users to unsubscribe from this list

bind-users mailing list
[hidden email]
https://lists.isc.org/mailman/listinfo/bind-users
Reply | Threaded
Open this post in threaded view
|

Re: Latest BIND: Error "rpz_rewrite_name: mismatched summary data; continuing"

Tom Tom

Hi list
After some more troubleshooting, I was able to locate the problem:
- One Spamhaus-Zone-File (dbl.rpz.spamhaus.org, ca. 180MB in "masterfile-format text;") is loaded correctly, but if this zone is loaded, then I got the mentioned errors.
- Configuring the "masterfile-format map;" for this zone, then the error disappered.


Any hints for this behaviour?

Kind regards,




On 08/30/2016 06:53 AM, Tom wrote:

Hi list

Using self-compiled latest bind (9.10.4-P2):

I have a bind-setup with activated response-policy-zones. For each client-forward-query, which has a valid dns-response, I got an error in the client-log (for NXDOMAIN-Reponses, I didn't have such errors... ex. "dig @nameserver aasledkfjasdlkfjsadlf.asdlfkjsadlfkjasdjflk"):

- 30-Aug-2016 06:43:51.722 client: error: query client=0x7f1074112200 thread=0x7f107a8a7700 (google.com/A): rpz_rewrite_name: mismatched summary data; continuing

- 30-Aug-2016 06:46:19.312 client: error: query client=0x7f10741614e0 thread=0x7f107b0a8700 (yahoo.com/A): rpz_rewrite_name: mismatched summary data; continuing

...
...

The client receives the right response, dns-rpz is also working, but I'm suspicious about the errors mentioned above. Any hints?
Thanks a lot.

Kind regards,
Tom


_______________________________________________
Please visit https://lists.isc.org/mailman/listinfo/bind-users to unsubscribe from this list

bind-users mailing list
[hidden email]
https://lists.isc.org/mailman/listinfo/bind-users
Reply | Threaded
Open this post in threaded view
|

Re: Latest BIND: Error "rpz_rewrite_name: mismatched summary data; continuing"

Tom Tom

Sorry...wrong post. After a little bit more testing, the errors are still appearing. The masterfile-format didn't solved the errors....

Thank you,

Tom



On 08/30/2016 08:20 AM, Tom wrote:

Hi list
After some more troubleshooting, I was able to locate the problem:
- One Spamhaus-Zone-File (dbl.rpz.spamhaus.org, ca. 180MB in "masterfile-format text;") is loaded correctly, but if this zone is loaded, then I got the mentioned errors.
- Configuring the "masterfile-format map;" for this zone, then the error disappered.


Any hints for this behaviour?

Kind regards,




On 08/30/2016 06:53 AM, Tom wrote:

Hi list

Using self-compiled latest bind (9.10.4-P2):

I have a bind-setup with activated response-policy-zones. For each client-forward-query, which has a valid dns-response, I got an error in the client-log (for NXDOMAIN-Reponses, I didn't have such errors... ex. "dig @nameserver aasledkfjasdlkfjsadlf.asdlfkjsadlfkjasdjflk"):

- 30-Aug-2016 06:43:51.722 client: error: query client=0x7f1074112200 thread=0x7f107a8a7700 (google.com/A): rpz_rewrite_name: mismatched summary data; continuing

- 30-Aug-2016 06:46:19.312 client: error: query client=0x7f10741614e0 thread=0x7f107b0a8700 (yahoo.com/A): rpz_rewrite_name: mismatched summary data; continuing

...
...

The client receives the right response, dns-rpz is also working, but I'm suspicious about the errors mentioned above. Any hints?
Thanks a lot.

Kind regards,
Tom



_______________________________________________
Please visit https://lists.isc.org/mailman/listinfo/bind-users to unsubscribe from this list

bind-users mailing list
[hidden email]
https://lists.isc.org/mailman/listinfo/bind-users
Reply | Threaded
Open this post in threaded view
|

Re: Latest BIND: Error "rpz_rewrite_name: mismatched summary data; continuing"

Tony Finch
In reply to this post by Tom Tom
Tom <[hidden email]> wrote:
>
> I have a bind-setup with activated response-policy-zones. For *each*
> client-forward-query, which has a valid dns-response, I got an error in the
> client-log (for NXDOMAIN-Reponses, I didn't have such errors... ex. "dig
> @nameserver aasledkfjasdlkfjsadlf.asdlfkjsadlfkjasdjflk"):

There's a comment before this error message saying:

        /*
         * Continue after a policy record that is missing
         * contrary to the summary data.  The summary
         * data can out of date during races with and among
         * policy zone updates.
         */

Spamhaus RPZ updates frequently, which might be related to your problem.
However I would not expect an update race to cause a complaint for every
query...

Tony.
--
f.anthony.n.finch  <[hidden email]>  http://dotat.at/  -  I xn--zr8h punycode
Viking, North Utsire: Southerly or southwesterly 5 to 7. Moderate,
occasionally rough. Rain or showers. Good, occasionally moderate.
_______________________________________________
Please visit https://lists.isc.org/mailman/listinfo/bind-users to unsubscribe from this list

bind-users mailing list
[hidden email]
https://lists.isc.org/mailman/listinfo/bind-users
Reply | Threaded
Open this post in threaded view
|

Re: Latest BIND: Error "rpz_rewrite_name: mismatched summary data; continuing"

Tom Tom
Is there a workaround/configuration-directive not to log every request
with this "error"? One way would be using BIND 9.9.9-P2 (because this
code was added in 9.10.x...), but I would prefer 9.10.x.

Kind regards,
Tom



On 08/31/2016 03:05 PM, Tony Finch wrote:

> Tom <[hidden email]> wrote:
>> I have a bind-setup with activated response-policy-zones. For *each*
>> client-forward-query, which has a valid dns-response, I got an error in the
>> client-log (for NXDOMAIN-Reponses, I didn't have such errors... ex. "dig
>> @nameserver aasledkfjasdlkfjsadlf.asdlfkjsadlfkjasdjflk"):
> There's a comment before this error message saying:
>
> /*
> * Continue after a policy record that is missing
> * contrary to the summary data.  The summary
> * data can out of date during races with and among
> * policy zone updates.
> */
>
> Spamhaus RPZ updates frequently, which might be related to your problem.
> However I would not expect an update race to cause a complaint for every
> query...
>
> Tony.

_______________________________________________
Please visit https://lists.isc.org/mailman/listinfo/bind-users to unsubscribe from this list

bind-users mailing list
[hidden email]
https://lists.isc.org/mailman/listinfo/bind-users
Reply | Threaded
Open this post in threaded view
|

Re: Latest BIND: Error "rpz_rewrite_name: mismatched summary data; continuing"

Mukund Sivaraman
Hi Tom

On Tue, Sep 06, 2016 at 07:37:50AM +0200, Tom wrote:
> Is there a workaround/configuration-directive not to log every request with
> this "error"? One way would be using BIND 9.9.9-P2 (because this code was
> added in 9.10.x...), but I would prefer 9.10.x.

(1) Don't use regular BIND 9.9 for RPZ. For using RPZ, please use 9.10
and higher (or 9.9 subscription branch that's available to ISC
customers). RPZ in vanilla 9.9 is unmaintained and unsupported (it was
experimental there).

(2) We'll look at tweaking this log message, but if you want to just not
see this log message, just recompile after removing the offending CTRACE
statement from bin/named/query.c. In fact, this code is normally enabled
when configured with --enable-querytrace. Do you have query tracing
configured? Is seeing this additional log message so inconvenient then?

                Mukund

_______________________________________________
Please visit https://lists.isc.org/mailman/listinfo/bind-users to unsubscribe from this list

bind-users mailing list
[hidden email]
https://lists.isc.org/mailman/listinfo/bind-users

signature.asc (817 bytes) Download Attachment
Reply | Threaded
Open this post in threaded view
|

Re: Latest BIND: Error "rpz_rewrite_name: mismatched summary data; continuing"

Tom Tom
Hi Mukund

Many thanks for your hint. In fact named was compiled with
"--enable-querytrace". After recompiling 9.10.4-P2 without querytrace,
the log looks good.

Kind regards,
Tom



On 09/06/2016 09:32 AM, Mukund Sivaraman wrote:

> Hi Tom
>
> On Tue, Sep 06, 2016 at 07:37:50AM +0200, Tom wrote:
>> Is there a workaround/configuration-directive not to log every request with
>> this "error"? One way would be using BIND 9.9.9-P2 (because this code was
>> added in 9.10.x...), but I would prefer 9.10.x.
>
> (1) Don't use regular BIND 9.9 for RPZ. For using RPZ, please use 9.10
> and higher (or 9.9 subscription branch that's available to ISC
> customers). RPZ in vanilla 9.9 is unmaintained and unsupported (it was
> experimental there).
>
> (2) We'll look at tweaking this log message, but if you want to just not
> see this log message, just recompile after removing the offending CTRACE
> statement from bin/named/query.c. In fact, this code is normally enabled
> when configured with --enable-querytrace. Do you have query tracing
> configured? Is seeing this additional log message so inconvenient then?
>
> Mukund
>
_______________________________________________
Please visit https://lists.isc.org/mailman/listinfo/bind-users to unsubscribe from this list

bind-users mailing list
[hidden email]
https://lists.isc.org/mailman/listinfo/bind-users
Reply | Threaded
Open this post in threaded view
|

Re: Latest BIND: Error "rpz_rewrite_name: mismatched summary data; continuing"

Bind-Users forum mailing list
In reply to this post by Mukund Sivaraman
Hi,

I'm resurrecting an old thread:

>> Is there a workaround/configuration-directive not to log every request with
>> this "error"? One way would be using BIND 9.9.9-P2 (because this code was
>> added in 9.10.x...), but I would prefer 9.10.x.
>
> (1) Don't use regular BIND 9.9 for RPZ. For using RPZ, please use 9.10
> and higher (or 9.9 subscription branch that's available to ISC
> customers). RPZ in vanilla 9.9 is unmaintained and unsupported (it was
> experimental there).

I'm seeing the exact same behaviour with 9.12.4-P1 and 9.14.1.

We're using a fairly static RPZ setup with an RPZ zone containing
at the moment only some 225 nodes.

It seems that the frequency of the log messages is about as
stated: once for each and every query, perhaps for each query
where a lookup in the rpz zone gets a "doesn't exist" status,
which would be nearly all queries in our case.

I worry that this high frequency of logging might negatively
impact query performance...

> (2) We'll look at tweaking this log message, but if you want to just not
> see this log message, just recompile after removing the offending CTRACE
> statement from bin/named/query.c. In fact, this code is normally enabled
> when configured with --enable-querytrace. Do you have query tracing
> configured? Is seeing this additional log message so inconvenient then?

I think there must be something wrong with the log message.  It
seems excessive to log this message about once per query,
especially since it seems to (misleadingly?) indicate an error
condition?  I'm not intimate enough with the code to suggest what
the exact problem is, though.

And ... as stated, configuring without --enable-querytrace
removes the log message.

Regards,

- Håvard
_______________________________________________
Please visit https://lists.isc.org/mailman/listinfo/bind-users to unsubscribe from this list

bind-users mailing list
[hidden email]
https://lists.isc.org/mailman/listinfo/bind-users
Reply | Threaded
Open this post in threaded view
|

Re: Latest BIND: Error "rpz_rewrite_name: mismatched summary data; continuing"

Mukund Sivaraman-2
On Fri, Apr 26, 2019 at 10:08:43PM +0200, Havard Eidnes via bind-users wrote:

> > (2) We'll look at tweaking this log message, but if you want to just not
> > see this log message, just recompile after removing the offending CTRACE
> > statement from bin/named/query.c. In fact, this code is normally enabled
> > when configured with --enable-querytrace. Do you have query tracing
> > configured? Is seeing this additional log message so inconvenient then?
>
> I think there must be something wrong with the log message.  It
> seems excessive to log this message about once per query,
> especially since it seems to (misleadingly?) indicate an error
> condition?  I'm not intimate enough with the code to suggest what
> the exact problem is, though.
>
> And ... as stated, configuring without --enable-querytrace
> removes the log message.

I can't speak for ISC BIND 9 (you seem to have mailed my old email
address), but --enable-querytrace was not meant to be used in
production. One should expect to observe excessive logging when it is
configured so, because that's what the configure argument implies
("perform abundant logging about query processing even if it hurts
performance").

To summarize, the log message is that the code has observed something
unexpected (the carpet has been pulled from under it) but it copes with
it. Perhaps the logging call can be removed from the code.

In more detail, BIND uses a per-view RPZ summary data structure from the
contents of response policy zones configured within that view. The
summary datastructure is a singular combination of the contents of all
the RPZ zones from that view, so that queried names can be efficiently
matched against RPZ triggers in the query path. The summary
datastructure is built and updated when the RPZ zones it is dependent on
are updated. The logged message complains that the RPZ summary
datastructure is out-of-sync with the RPZ zones, and so named was not
able to lookup the action for a trigger from the RPZ zone it was looking
at. In this case, named tries to continue from the next matching zone in
precedence.

                Mukund
_______________________________________________
Please visit https://lists.isc.org/mailman/listinfo/bind-users to unsubscribe from this list

bind-users mailing list
[hidden email]
https://lists.isc.org/mailman/listinfo/bind-users
Reply | Threaded
Open this post in threaded view
|

Re: Latest BIND: Error "rpz_rewrite_name: mismatched summary data; continuing"

Bind-Users forum mailing list
>> I think there must be something wrong with the log message.  It
>> seems excessive to log this message about once per query,
>> especially since it seems to (misleadingly?) indicate an error
>> condition?  I'm not intimate enough with the code to suggest what
>> the exact problem is, though.
>>
>> And ... as stated, configuring without --enable-querytrace
>> removes the log message.
>
> I can't speak for ISC BIND 9 (you seem to have mailed my old email
> address)[...]

That was the one sitting in the old bind-users@ messages...

> [...] but --enable-querytrace was not meant to be used in
> production. One should expect to observe excessive logging when it is
> configured so, because that's what the configure argument implies
> ("perform abundant logging about query processing even if it hurts
> performance").

OK, that's now clear to me.  For some reason I had mixed up the
potential for "query logging" with "query tracing".

> To summarize, the log message is that the code has observed something
> unexpected (the carpet has been pulled from under it) but it copes with
> it. Perhaps the logging call can be removed from the code.
>
> In more detail, BIND uses a per-view RPZ summary data structure from the
> contents of response policy zones configured within that view. The
> summary datastructure is a singular combination of the contents of all
> the RPZ zones from that view, so that queried names can be efficiently
> matched against RPZ triggers in the query path. The summary
> datastructure is built and updated when the RPZ zones it is dependent on
> are updated. The logged message complains that the RPZ summary
> datastructure is out-of-sync with the RPZ zones, and so named was not
> able to lookup the action for a trigger from the RPZ zone it was looking
> at. In this case, named tries to continue from the next matching zone in
> precedence.

I've now replicated the setup on my local workstation, and I can confirm
that the "rpz_rewrite_name: mismatched summary data; continuing" log
message is happening at least once per received query (confirmed by
temporarily also turning on query logging).

There's no race here (the rpz zone hasn't been updated today).  So
either the code doesn't actually work the way it's supposed to, and this
is a valid error condition, or the error message itself is misleading
and the condition which triggers the logging is "normal".

Reading what you say above leads me to beleive that there is an internal
inconsistency in the RPZ datastructures -- that the "summary data
structure" says one thing about the queried-for name, while an actual
lookup in the RPZ zones gives a different result, and therefore that the
log message is in some sense "valid" and points out this inconsistency.

I've addd some logging here and there, and have verified that both
rpz_get_zbits() and dns_rpz_find_name() both indicates that they've
found a match(?) (zbits != 0), while looking up the name with
rpz_find_p() returns DNS_R_NXDOMAIN, which I think indicates "no rpz
handling for this queried-for name".  It would thus seem to me that the
intended optimization(?) of at least dns_rpzz_find_name() isn't actually
working at all, and when RPZ processing is turned on, all lookups end up
going through rpz_find_p().

Debugging a bit further reveals that in my setup, dns_rbt_findnode()
inside of dns_rpz_find_name() always returns DNS_R_PARTIALMATCH.

The entries in our single rpz zone file all follow the following
pattern:

<blocked-domain>.<rpz-zone-name>. CNAME <some-local-host>.
*.<blocked-domain>.<rpz-zone-name>. CNAME <some-local-host>.

if that makes any difference.

Regards,

- Håvard
_______________________________________________
Please visit https://lists.isc.org/mailman/listinfo/bind-users to unsubscribe from this list

bind-users mailing list
[hidden email]
https://lists.isc.org/mailman/listinfo/bind-users