Tracking down validation failures

[Jeremy C. Reed]

On Thu, 11 Jun 2009, Chris Thompson wrote:

> We have recently turned on DNSSEC validation (using dlv.isc.org) in our
> main university-wide recursive nameservers, which are running BIND 9.6.1rc1.
> 
> No-one is actually complaining, but the counts I am seeing for "ValFail"
> on the statistics channel are quite a bit higher than we were seeing
> during testing, running at 0.2% - 0.4% of "ValAttempt" (but the counter
> increases in bursts), and I would be happier knowing what they were
> coming from.

Have a look at the new (experimental) query-errors category.  For example:

11-Jun-2009 12:59:43.332 query-errors: debug 1: client 127.0.0.1#59980: 
query failed (SERVFAIL) for advocaat.pro/IN/SOA at query.c:4626

11-Jun-2009 12:59:43.332 query-errors: debug 2: fetch completed at 
resolver.c:2995 for advocaat.pro/SOA in 0.422699: failure/insecurity proof 
failed [domain:pro,referral:1,restart:2,qrysent:4,timeout:0,lame:0,
neterr:0,badresp:0,adberr:0,findfail:0,valfail:4]

It is way less noisy than the dnssec logging.

Also you should see some of the logging by default in the lame-servers 
category (at level "info") such as:

Jun 11 12:59:43 tx named[1490]: error (insecurity proof failed) resolving 
'advocaat.pro/SOA/IN': 192.149.63.10#53
Jun 11 12:59:43 tx named[1490]: error (insecurity proof failed) resolving 
'advocaat.pro/SOA/IN': 192.149.62.10#53
Jun 11 12:59:43 tx named[1490]: error (insecurity proof failed) resolving 
'advocaat.pro/SOA/IN': 192.149.64.10#53
Jun 11 12:59:43 tx named[1490]: error (insecurity proof failed) resolving 
'advocaat.pro/SOA/IN': 192.149.66.10#53

(see valfail count above is 4)