resolver, watcher: a record type whose query fails keeps its previous records (closes #231)

The resolver lists in FailedTypes each record type whose query to a
nameserver got no usable reply (none after two tries, an error reply, a
referral, or a truncated reply whose TCP retry failed), and logs it with
the reason unless shutdown cut it short. A nameserver that answered no
type has failed, as before.
The watcher saves such a type in failedTypes, keeping the previous
check's records, leaves it out of the comparison with other nameservers
on that check, and compares the kept records with the next answer. With
nothing to keep, it is also in unknownTypes and not compared until it
answers. Change messages leave out what was not compared. A nameserver
whose A, AAAA or CNAME query failed is no answer when following a CNAME
or resolving addresses.

Model: opus-5-5

TODO.md

@@ -21,6 +21,8 @@ trial run of the finished image: https://git.eeqj.de/sneak/dnswatcher/issues/149
 
 - 2026-10-02: a record type whose query to a nameserver fails keeps its previous
   records and alerts nothing; the other types are still saved (closes #231).
+- 2026-10-02: a DNS lookup that shutdown cuts short logs no error; one that
+  fails otherwise, or runs out of time, still does (closes #229).
 - 2026-10-02: Record Change and Inconsistency notifications list only the record
   types that differ, each with its values as plain text (closes #219).
 - 2026-10-02: the startup notification no longer says every notification

internal/resolver/iterative.go

@@ -646,7 +646,8 @@ type queryState struct {
 
 // queryEachType asks the nameserver at nsIP about hostname once for each
 // record type in qtypes, and lists in resp.FailedTypes the types whose
-// query got no usable reply, logging each with the reason.
+// query got no usable reply, logging each with the reason unless ctx was
+// cancelled: shutdown cancels it, and a query it cut short did not fail.
 func (r *Resolver) queryEachType(
 	ctx context.Context,
 	nsIP string,
@@ -671,6 +672,10 @@ func (r *Resolver) queryEachType(
 		rtype := dns.TypeToString[qtype]
 		resp.FailedTypes = append(resp.FailedTypes, rtype)
 
+		if errors.Is(ctx.Err(), context.Canceled) {
+			continue
+		}
+
 		r.log.Warn(
 			"record type query failed",
 			"hostname", hostname,

internal/resolver/resolver_test.go

@@ -890,6 +890,29 @@ func TestQueryNameserverIP_Timeout(t *testing.T) {
 	assert.NotEmpty(t, resp.Error)
 }
 
+// TestQueryNameserverIP_CancelledLogsNothing cancels the context while
+// a query to 192.0.2.1, where nothing answers, is waiting for a reply,
+// as shutdown does. The query was cut short, not failed, so nothing is
+// logged.
+func TestQueryNameserverIP_CancelledLogsNothing(t *testing.T) {
+	t.Parallel()
+
+	var logs bytes.Buffer
+
+	r := resolver.NewFromLogger(slog.New(slog.NewTextHandler(&logs, nil)))
+
+	ctx, cancel := context.WithCancel(context.Background())
+	t.Cleanup(cancel)
+	time.AfterFunc(100*time.Millisecond, cancel)
+
+	_, err := r.QueryNameserverIP(
+		ctx, "unreachable.test.", "192.0.2.1", "example.com",
+	)
+	require.NoError(t, err)
+
+	assert.Empty(t, logs.String())
+}
+
 // TestCollectIPs_NoNameserverAnswered takes the response of a
 // nameserver at 192.0.2.1, where nothing answers, as
 // TestQueryNameserverIP_Timeout does. Addresses collected from

internal/watcher/cancelled_test.go

@@ -1,10 +1,13 @@
 package watcher_test
 
 import (
+	"bytes"
 	"context"
 	"log/slog"
 	"reflect"
+	"strings"
 	"testing"
+	"time"
 
 	"sneak.berlin/go/dnswatcher/internal/portcheck"
 	"sneak.berlin/go/dnswatcher/internal/resolver"
@@ -79,3 +82,72 @@ func TestCancelledCheckSavesNothing(t *testing.T) {
 		t.Errorf("sent %v, want no notifications", notifications)
 	}
 }
+
+// newLoggingWatcher returns a watcher for a domain and a hostname, with
+// the real resolver, that writes what it logs at warning level or above
+// into the returned buffer.
+func newLoggingWatcher(t *testing.T) (*watcher.Watcher, *bytes.Buffer) {
+	t.Helper()
+
+	cfg := defaultTestConfig(t)
+	cfg.Domains = []string{testSmallDomain}
+	cfg.Hostnames = []string{host}
+
+	w, _ := newTestWatcher(t, cfg)
+
+	logs := &bytes.Buffer{}
+	w.SetLogger(slog.New(slog.NewJSONHandler(
+		logs, &slog.HandlerOptions{Level: slog.LevelWarn},
+	)))
+
+	return w, logs
+}
+
+// TestLookupCutShortIsNotLogged checks a domain and a hostname, looks
+// up a nameserver's addresses and follows a CNAME, with the context
+// cancelled, as shutdown leaves it. The real resolver fails each lookup
+// without sending a query. Shutdown cutting a lookup short is not a
+// failure, so nothing may be logged at warning level or above.
+func TestLookupCutShortIsNotLogged(t *testing.T) {
+	t.Parallel()
+
+	w, logs := newLoggingWatcher(t)
+
+	ctx, cancel := context.WithCancel(t.Context())
+	cancel()
+
+	w.RunOnce(ctx)
+	w.ResolveNameserverAddresses(ctx, []string{nsA}, nil)
+	w.ResolveCNAMEAddresses(ctx, host, cnameState(), nil)
+
+	if logs.Len() > 0 {
+		t.Errorf("logged at warning level or above:\n%s", logs)
+	}
+}
+
+// TestLookupOutOfTimeIsLoggedAsError does what
+// TestLookupCutShortIsNotLogged does, with the context's deadline passed
+// instead. A lookup that ran out of time did fail, so the domain's NS
+// lookup, the hostname's lookup, the nameserver's address lookup and the
+// CNAME's are each logged as an error.
+func TestLookupOutOfTimeIsLoggedAsError(t *testing.T) {
+	t.Parallel()
+
+	w, logs := newLoggingWatcher(t)
+
+	ctx, cancel := context.WithDeadline(t.Context(), time.Now())
+	t.Cleanup(cancel)
+
+	w.RunOnce(ctx)
+	w.ResolveNameserverAddresses(ctx, []string{nsA}, nil)
+	w.ResolveCNAMEAddresses(ctx, host, cnameState(), nil)
+
+	const want = 4
+
+	lines := strings.Count(logs.String(), "\n")
+	errorLines := strings.Count(logs.String(), `"level":"ERROR"`)
+
+	if lines != want || errorLines != want {
+		t.Errorf("logged:\n%s\nwant %d lines, each at error level", logs, want)
+	}
+}

internal/watcher/export_test.go

@@ -31,6 +31,12 @@ func NewForTest(
 	}
 }
 
+// SetLogger replaces the watcher's logger, so a test can read what it
+// logs.
+func (w *Watcher) SetLogger(log *slog.Logger) {
+	w.log = log
+}
+
 // NewlyDisagreeingPairs exports newlyDisagreeingPairs for testing.
 func NewlyDisagreeingPairs(
 	prev, current *state.HostnameState,

internal/watcher/watcher.go

@@ -2,6 +2,7 @@ package watcher
 
 import (
 	"context"
+	"errors"
 	"fmt"
 	"log/slog"
 	"maps"
@@ -214,13 +215,29 @@ func (w *Watcher) runDNSChecks(ctx context.Context) {
 	}
 }
 
+// logFailedLookup logs a failed DNS lookup at error level, unless ctx
+// was cancelled: shutdown cancels it, and a lookup it cut short did not
+// fail. A lookup that ran out of time did fail, so it is logged.
+func (w *Watcher) logFailedLookup(
+	ctx context.Context,
+	msg string,
+	args ...any,
+) {
+	if errors.Is(ctx.Err(), context.Canceled) {
+		return
+	}
+
+	w.log.Error(msg, args...)
+}
+
 func (w *Watcher) checkDomain(
 	ctx context.Context,
 	domain string,
 ) {
 	nameservers, err := w.resolver.LookupNS(ctx, domain)
 	if err != nil {
-		w.log.Error(
+		w.logFailedLookup(
+			ctx,
 			"failed to lookup NS",
 			"domain", domain,
 			"error", err,
@@ -321,7 +338,8 @@ func (w *Watcher) resolveNameserverAddresses(
 			continue
 		}
 
-		w.log.Error(
+		w.logFailedLookup(
+			ctx,
 			"no addresses found for nameserver",
 			"nameserver", ns,
 			"error", err,
@@ -373,7 +391,8 @@ func (w *Watcher) checkHostname(
 ) {
 	results, err := w.resolver.LookupAllRecords(ctx, hostname)
 	if err != nil {
-		w.log.Error(
+		w.logFailedLookup(
+			ctx,
 			"failed to lookup records",
 			"hostname", hostname,
 			"error", err,
@@ -462,7 +481,8 @@ func (w *Watcher) resolveCNAMEAddresses(
 	for target := range targets {
 		ips, err := w.resolver.ResolveIPAddresses(ctx, target)
 		if err != nil {
-			w.log.Error(
+			w.logFailedLookup(
+				ctx,
 				"failed to follow CNAME",
 				"hostname", hostname,
 				"target", target,