Fix block-answer TTLs that were nanoseconds, and stop counting NXDOMAIN as an error

Both found by running the resolver locally against real upstreams.

response_ttl is a duration (60s) and a DNS TTL is seconds, but eight places
converted with a bare uint32(), which keeps the low 32 bits of the nanosecond
count. A blocked name's negative answer carried an SOA TTL and minimum of
997195776 (about 31 years), so any client or downstream cache that honoured it
would remember the block, and keep remembering it after the name was
unblocked. blocklist.TTLSeconds converts properly (whole seconds, clamped to
2^31-1) and is used by the rule parser and the block, sinkhole and redirect
answers. The tests read the TTL off the wire; with the old conversion they fail
with 4165425152.

An ordinary upstream NXDOMAIN was classified as an error. A name that does not
exist is the normal result of a typo, a search-domain expansion or a leaked mDNS
query, so on a real network the error metric counted mostly those and, with the
access log's errors-only default, every one wrote a line. Only the upstream
failing or refusing (SERVFAIL, REFUSED, FORMERR, NOTIMP) is an error now.

Co-Authored-By: Claude Sonnet 5.5 <noreply@anthropic.com>

internal/app/accesslog_test.go

@@ -46,6 +46,10 @@ func TestAccessLogDefaultsToBlockedAndFailed(t *testing.T) {
 
 	h.query("www.example.test", dns.TypeA) // allowed
 	h.query("www.example.test", dns.TypeA) // cached
+	// A name that does not exist is an answer, not an error worth a line.
+	if m := h.query("no-such-name.example.org", dns.TypeA); m.Rcode != dns.RcodeNameError {
+		t.Fatalf("setup: no-such-name.example.org rcode %d, want NXDOMAIN", m.Rcode)
+	}
 	if m := h.query("ads.example.com", dns.TypeA); m.Rcode != dns.RcodeNameError {
 		t.Fatalf("setup: ads.example.com rcode %d, want a block", m.Rcode)
 	}
@@ -53,7 +57,7 @@ func TestAccessLogDefaultsToBlockedAndFailed(t *testing.T) {
 
 	lines := out.lines()
 	if len(lines) != 1 {
-		t.Fatalf("%d access-log lines, want exactly the blocked query: %v", len(lines), lines)
+		t.Fatalf("%d access-log lines, want exactly the blocked query (not the allowed, cached or NXDOMAIN ones): %v", len(lines), lines)
 	}
 	l := lines[0]
 	for k, want := range map[string]any{

internal/blocklist/manager.go

@@ -379,7 +379,7 @@ func (m *Manager) loadOne(ctx context.Context, cfg *config.Config, l config.List
 	format := Format(l.Format)
 	opt := ParseOptions{
 		Subdomains: true,
-		DefaultTTL: uint32(cfg.Block.ResponseTTL.D()),
+		DefaultTTL: TTLSeconds(cfg.Block.ResponseTTL.D()),
 		Categories: l.Categories,
 	}
 	rules, st, perr := Parse(format, data, opt)
@@ -624,7 +624,7 @@ func parseInline(entries []string, action Action, ttl config.Duration) ([]Rule,
 		sb.WriteString(e)
 		sb.WriteByte('\n')
 	}
-	opt := ParseOptions{Subdomains: true, DefaultTTL: uint32(ttl.D())}
+	opt := ParseOptions{Subdomains: true, DefaultTTL: TTLSeconds(ttl.D())}
 	rules, st, err := Parse(FormatPlain, []byte(sb.String()), opt)
 	if err != nil {
 		return nil, st, err
@@ -668,3 +668,17 @@ func fraction(name string) int {
 // insecureTLS is the transport tweak for sources that need it. It is only
 // reachable when a list explicitly sets insecure_skip_tls_verify.
 func insecureTLS() *tls.Config { return &tls.Config{InsecureSkipVerify: true} }
+
+// TTLSeconds converts a duration to a DNS TTL: whole seconds, never negative,
+// and no more than the 2^31-1 RFC 2181 allows. A TTL is seconds on the wire and
+// a config duration is nanoseconds in memory; converting with a bare uint32
+// truncates the nanoseconds into a number nobody meant.
+func TTLSeconds(d time.Duration) uint32 {
+	switch {
+	case d <= 0:
+		return 0
+	case d >= time.Duration(1<<31-1)*time.Second:
+		return 1<<31 - 1
+	}
+	return uint32(d / time.Second)
+}

internal/blocklist/manager_ttl_test.go

@@ -0,0 +1,20 @@
+package blocklist
+
+import (
+	"testing"
+	"time"
+
+	"git.k8s-git-k6n.net/mats/fancy-dns/internal/config"
+)
+
+// TestInlineRulesGetTheResponseTTLInSeconds: the rule TTL is seconds, the config
+// value is a duration, and the two were once confused.
+func TestInlineRulesGetTheResponseTTLInSeconds(t *testing.T) {
+	rules, _, err := parseInline([]string{"a.example"}, ActionBlock, config.Duration(90*time.Second))
+	if err != nil || len(rules) != 1 {
+		t.Fatalf("%v %v", rules, err)
+	}
+	if rules[0].TTL != 90 {
+		t.Errorf("rule TTL = %d, want 90", rules[0].TTL)
+	}
+}

internal/engine/blockttl_test.go

@@ -0,0 +1,76 @@
+package engine
+
+import (
+	"testing"
+	"time"
+
+	"github.com/miekg/dns"
+
+	"git.k8s-git-k6n.net/mats/fancy-dns/internal/blocklist"
+	"git.k8s-git-k6n.net/mats/fancy-dns/internal/config"
+)
+
+// soaTTLs returns the TTL and minimum of the SOA in a response's authority
+// section.
+func soaTTLs(t *testing.T, m *dns.Msg) (ttl, min uint32) {
+	t.Helper()
+	for _, rr := range m.Ns {
+		if soa, ok := rr.(*dns.SOA); ok {
+			return soa.Hdr.Ttl, soa.Minttl
+		}
+	}
+	t.Fatalf("no SOA in %v", m)
+	return 0, 0
+}
+
+// TestBlockedAnswersCarryTheConfiguredTTLInSeconds: response_ttl is a duration
+// ("60s"), and the TTL on the wire is seconds. The conversion once took the
+// duration's nanoseconds as seconds and truncated them, so a blocked name's
+// negative answer told every client to remember it for about thirty years.
+func TestBlockedAnswersCarryTheConfiguredTTLInSeconds(t *testing.T) {
+	const want = 60 // config.Default's response_ttl
+
+	t.Run("nxdomain", func(t *testing.T) {
+		h := newHarness(t, hopt{rules: []blocklist.Rule{{Name: "blocked.example.test"}}})
+		res := h.ask("blocked.example.test.", dns.TypeA)
+		requireRcode(t, res, dns.RcodeNameError)
+		if ttl, min := soaTTLs(t, res.Msg); ttl != want || min != want {
+			t.Errorf("SOA ttl=%d minimum=%d, want %d", ttl, min, want)
+		}
+	})
+	t.Run("zero", func(t *testing.T) {
+		h := newHarness(t, hopt{
+			blockCfg: func(b *config.Block) { b.DefaultAction = "zero" },
+			rules:    []blocklist.Rule{{Name: "blocked.example.test"}},
+		})
+		res := h.ask("blocked.example.test.", dns.TypeA)
+		if len(res.Msg.Answer) != 1 || res.Msg.Answer[0].Header().Ttl != want {
+			t.Errorf("answer = %v, want one record with TTL %d", res.Msg.Answer, want)
+		}
+	})
+	t.Run("a rule's own ttl", func(t *testing.T) {
+		h := newHarness(t, hopt{rules: []blocklist.Rule{{Name: "blocked.example.test", TTL: 120}}})
+		res := h.ask("blocked.example.test.", dns.TypeA)
+		if ttl, _ := soaTTLs(t, res.Msg); ttl != 120 {
+			t.Errorf("SOA ttl = %d, want the rule's 120", ttl)
+		}
+	})
+	t.Run("redirect", func(t *testing.T) {
+		h := newHarness(t, hopt{rules: []blocklist.Rule{{Name: "blocked.example.test", Action: blocklist.ActionRedirect, Response: "10.9.9.9"}}})
+		res := h.ask("blocked.example.test.", dns.TypeA)
+		if len(res.Msg.Answer) != 1 || res.Msg.Answer[0].Header().Ttl != want {
+			t.Errorf("answer = %v, want one record with TTL %d", res.Msg.Answer, want)
+		}
+	})
+}
+
+func TestTTLSecondsClamps(t *testing.T) {
+	for in, want := range map[time.Duration]uint32{
+		0: 0, 60 * time.Second: 60, 1500 * time.Millisecond: 1, 24 * time.Hour: 86400,
+		-time.Second: 0, 1000000 * time.Hour: 1<<31 - 1,
+	} {
+		if got := blocklist.TTLSeconds(in); got != want {
+			t.Errorf("TTLSeconds(%v) = %d, want %d", in, got, want)
+		}
+	}
+}

internal/engine/coalesce_test.go

@@ -9,6 +9,7 @@ import (
 
 	"github.com/miekg/dns"
 
+	"git.k8s-git-k6n.net/mats/fancy-dns/internal/accesslog"
 	"git.k8s-git-k6n.net/mats/fancy-dns/internal/config"
 )
 
@@ -215,3 +216,19 @@ func TestUnpopularEntryIsNotRefreshed(t *testing.T) {
 		t.Fatalf("a once-asked name was refreshed: %d upstream queries", got)
 	}
 }
+
+// TestNXDOMAINIsAnAnswerNotAnError: a name that does not exist is a normal
+// result. Counting it as an error buried real errors in the metrics and, with
+// the access log logging errors by default, wrote a line for every typo.
+func TestNXDOMAINIsAnAnswerNotAnError(t *testing.T) {
+	h := newHarness(t, hopt{})
+	before := h.totals()
+	res := h.ask("no-such-name.example.com.", dns.TypeA) // the fake upstream says NXDOMAIN outside .test
+	requireRcode(t, res, dns.RcodeNameError)
+	if res.Action != accesslog.ActionAllow {
+		t.Errorf("action = %q, want allow", res.Action)
+	}
+	if got := h.totals().Errors - before.Errors; got != 0 {
+		t.Errorf("the error counter moved by %d for an NXDOMAIN", got)
+	}
+}

internal/engine/engine.go

@@ -467,11 +467,13 @@ func (e *Engine) Handle(ctx context.Context, req Request) Response {
 	res.Msg = reply
 	res.Upstream = addr
 	res.Action = accesslog.ActionAllow
-	// A non-success RCODE is reported as an error through finish's metrics
-	// call, so the counters stay in one place.
-	if reply.Rcode != dns.RcodeServerFailure && reply.Rcode != dns.RcodeSuccess {
-		res.Action = accesslog.ActionError
-	} else if reply.Rcode == dns.RcodeServerFailure {
+	// NXDOMAIN is an answer, not a failure: a name that does not exist is the
+	// normal result of a typo, a search-domain expansion or a leaked mDNS
+	// query, and on a real network there are a great many of them. Counting
+	// them as errors buried the real ones in the metrics and, with the access
+	// log's errors-only default, wrote a line for each. What is left is the
+	// upstream failing or refusing: SERVFAIL, REFUSED, FORMERR, NOTIMP.
+	if reply.Rcode != dns.RcodeSuccess && reply.Rcode != dns.RcodeNameError {
 		res.Action = accesslog.ActionError
 	}
 	if e.cache != nil && !decision.SkipCache {
@@ -701,7 +703,7 @@ func (e *Engine) blockedMsg(q *dns.Msg, entry *blocklist.Entry) *dns.Msg {
 	if entry != nil {
 		switch entry.Action {
 		case blocklist.ActionNXDomain:
-			return nxDomain(q, uint32(cfg.ResponseTTL))
+			return nxDomain(q, blocklist.TTLSeconds(cfg.ResponseTTL.D()))
 		case blocklist.ActionZero:
 			c := cfg
 			c.DefaultAction = "zero"
@@ -710,9 +712,9 @@ func (e *Engine) blockedMsg(q *dns.Msg, entry *blocklist.Entry) *dns.Msg {
 			}
 			return sinkhole(q, c)
 		case blocklist.ActionRedirect:
-			return redirect(q, entry.Response, uint32(cfg.ResponseTTL))
+			return redirect(q, entry.Response, blocklist.TTLSeconds(cfg.ResponseTTL.D()))
 		case blocklist.ActionCNAME:
-			return redirect(q, entry.Response, uint32(cfg.ResponseTTL))
+			return redirect(q, entry.Response, blocklist.TTLSeconds(cfg.ResponseTTL.D()))
 		}
 	}
 	return blockedResponse(q, cfg, entry)
@@ -1020,7 +1022,7 @@ func syntheticSOA(q *dns.Msg, ttl uint32) dns.RR {
 
 // blockedResponse builds the configured blocklist answer.
 func blockedResponse(q *dns.Msg, cfg config.Block, entry *blocklist.Entry) *dns.Msg {
-	ttl := uint32(cfg.ResponseTTL.D())
+	ttl := blocklist.TTLSeconds(cfg.ResponseTTL.D())
 	if ttl == 0 {
 		ttl = 60
 	}
@@ -1057,7 +1059,7 @@ func sinkhole(q *dns.Msg, cfg config.Block) *dns.Msg {
 	m := new(dns.Msg)
 	m.SetReply(q)
 	m.Authoritative = true
-	ttl := uint32(cfg.ResponseTTL.D())
+	ttl := blocklist.TTLSeconds(cfg.ResponseTTL.D())
 	if ttl == 0 {
 		ttl = 60
 	}