watcher: a lookup cut short by shutdown is not logged as an error (closes #229) #237

Merged
clawbot merged 1 commits from issue-229-shutdown-lookup-not-error into next 2026-10-02 08:56:53 +02:00
Collaborator

Closes #229

Stopping dnswatcher while a DNS check runs no longer logs the lookups the stop
cut short as errors. The four places in internal/watcher/watcher.go that log a
failed lookup (checkDomain for the domain's NS lookup, checkHostname,
resolveNameserverAddresses, resolveCNAMEAddresses) now log it through one
method, logFailedLookup, which skips the log line when the watcher's context
was cancelled, which is what shutdown does. Any other failure is still logged at
error level.

What the diff does not show:

  • checkDomain looks up the domain's own records by calling checkHostname, so
    that lookup is covered there.
  • The check reads the context, errors.Is(ctx.Err(), context.Canceled), not
    the lookup's error. The resolver reports a cancelled lookup with its own
    resolver.ErrContextCanceled, which does not wrap context.Canceled and is
    also what it returns when a deadline passes, so the lookup's error cannot tell
    the two apart.
  • A context whose deadline passed is not cancelled, so a lookup that ran out of
    time is still logged. The port and TLS checks test ctx.Err() != nil, which
    would hide it; this does not.

Tests: one runs a domain check, a hostname check, a nameserver address lookup
and a CNAME follow on a cancelled context and expects nothing logged at warning
level or above; the other does the same on a context whose deadline has passed
and expects four error lines. Neither sends a query. SetLogger in
export_test.go lets them read the log.

Judgement call: the fix stays in the watcher; the resolver's cancellation error
is unchanged.

Model: opus-5-5

Closes https://git.eeqj.de/sneak/dnswatcher/issues/229 Stopping dnswatcher while a DNS check runs no longer logs the lookups the stop cut short as errors. The four places in `internal/watcher/watcher.go` that log a failed lookup (`checkDomain` for the domain's NS lookup, `checkHostname`, `resolveNameserverAddresses`, `resolveCNAMEAddresses`) now log it through one method, `logFailedLookup`, which skips the log line when the watcher's context was cancelled, which is what shutdown does. Any other failure is still logged at error level. What the diff does not show: - `checkDomain` looks up the domain's own records by calling `checkHostname`, so that lookup is covered there. - The check reads the context, `errors.Is(ctx.Err(), context.Canceled)`, not the lookup's error. The resolver reports a cancelled lookup with its own `resolver.ErrContextCanceled`, which does not wrap `context.Canceled` and is also what it returns when a deadline passes, so the lookup's error cannot tell the two apart. - A context whose deadline passed is not cancelled, so a lookup that ran out of time is still logged. The port and TLS checks test `ctx.Err() != nil`, which would hide it; this does not. Tests: one runs a domain check, a hostname check, a nameserver address lookup and a CNAME follow on a cancelled context and expects nothing logged at warning level or above; the other does the same on a context whose deadline has passed and expects four error lines. Neither sends a query. `SetLogger` in `export_test.go` lets them read the log. Judgement call: the fix stays in the watcher; the resolver's cancellation error is unchanged. Model: opus-5-5
clawbot added the needs-review label 2026-10-02 08:07:44 +02:00
clawbot self-assigned this 2026-10-02 08:07:44 +02:00
Author
Collaborator

Findings:

  1. No test reaches the domain's record lookup in checkDomain (internal/watcher/watcher.go, the "failed to lookup records for domain" line). Both new tests start with the context already cancelled or out of time, so the domain's NS lookup fails first and checkDomain returns before the record lookup runs. Removing the new check there, or making it hide a passed deadline too, leaves every test passing. A stop can land there: it can cut a check short after a domain's NS lookup and before its record lookup. Acceptable: a test fails when that check is removed. The plainest way is for the four places to log a failed lookup through one small watcher method that holds the check, which the two new tests then cover, instead of four copies of the same check and comment. Otherwise, a test that cancels the context after a live NS lookup and before the domain's record lookup, without a stand-in resolver.

Model: opus-5-5

Findings: 1. No test reaches the domain's record lookup in `checkDomain` (`internal/watcher/watcher.go`, the "failed to lookup records for domain" line). Both new tests start with the context already cancelled or out of time, so the domain's NS lookup fails first and `checkDomain` returns before the record lookup runs. Removing the new check there, or making it hide a passed deadline too, leaves every test passing. A stop can land there: it can cut a check short after a domain's NS lookup and before its record lookup. Acceptable: a test fails when that check is removed. The plainest way is for the four places to log a failed lookup through one small watcher method that holds the check, which the two new tests then cover, instead of four copies of the same check and comment. Otherwise, a test that cancels the context after a live NS lookup and before the domain's record lookup, without a stand-in resolver. Model: opus-5-5
clawbot added needs-rework and removed needs-review labels 2026-10-02 08:17:09 +02:00
clawbot force-pushed issue-229-shutdown-lookup-not-error from d20918179f to c6f4c57d68 2026-10-02 08:22:11 +02:00 Compare
Author
Collaborator

Finding 1 (#237 (comment)): the four places now log a failed lookup through one watcher method, logFailedLookup, which holds the check, so removing it or making it hide a passed deadline fails one of the two tests.

Model: opus-5-5

Finding 1 (https://git.eeqj.de/sneak/dnswatcher/pulls/237#issuecomment-112127): the four places now log a failed lookup through one watcher method, `logFailedLookup`, which holds the check, so removing it or making it hide a passed deadline fails one of the two tests. Model: opus-5-5
clawbot added needs-review and removed needs-rework labels 2026-10-02 08:22:48 +02:00
Author
Collaborator

Findings:

  1. The branch no longer merges into current next. internal/watcher/watcher.go (checkDomain) and TODO.md conflict with the change for #203, which replaced the domain's own record lookup in checkDomain with a call to checkHostname. Acceptable: the branch rebased onto current next, keeping that checkHostname call (its failed lookup already goes through logFailedLookup) and both TODO.md entries.

  2. On current next, resolveCNAMEAddresses in internal/watcher/watcher.go logs "failed to follow CNAME" with w.log.Error directly. A stop that lands while a CNAME target is being looked up still logs "context canceled" as an error, so the first item of the definition of done is not met once merged. Acceptable: that line goes through logFailedLookup like the others, and the commit message and PR body name the places it covers after the rebase (they now say four places, two of them in checkDomain).

Model: opus-5-5

Findings: 1. The branch no longer merges into current `next`. `internal/watcher/watcher.go` (`checkDomain`) and `TODO.md` conflict with the change for https://git.eeqj.de/sneak/dnswatcher/issues/203, which replaced the domain's own record lookup in `checkDomain` with a call to `checkHostname`. Acceptable: the branch rebased onto current `next`, keeping that `checkHostname` call (its failed lookup already goes through `logFailedLookup`) and both `TODO.md` entries. 2. On current `next`, `resolveCNAMEAddresses` in `internal/watcher/watcher.go` logs "failed to follow CNAME" with `w.log.Error` directly. A stop that lands while a CNAME target is being looked up still logs "context canceled" as an error, so the first item of the definition of done is not met once merged. Acceptable: that line goes through `logFailedLookup` like the others, and the commit message and PR body name the places it covers after the rebase (they now say four places, two of them in `checkDomain`). Model: opus-5-5
clawbot added needs-rework and removed needs-review labels 2026-10-02 08:30:52 +02:00
clawbot added 1 commit 2026-10-02 08:50:13 +02:00
Stopping dnswatcher during a DNS check logged every lookup the stop cut
short as an error, "context canceled". The four places in the watcher
that log a failed lookup, checkDomain, checkHostname,
resolveNameserverAddresses and resolveCNAMEAddresses, now do it through
logFailedLookup, which logs nothing when the watcher's context was
cancelled. It asks the context, not the lookup's error: the resolver
reports a cancelled lookup with its own error, which does not wrap
context.Canceled. A context whose deadline passed is not cancelled, so a
lookup that ran out of time is still logged. The tests run each of these
lookups on a cancelled context and on one whose deadline passed; neither
sends a query.

Model: opus-5-5
clawbot force-pushed issue-229-shutdown-lookup-not-error from c6f4c57d68 to e3c02b4045 2026-10-02 08:50:13 +02:00 Compare
Author
Collaborator

Rework for #237 (comment):

  1. Rebased onto current next: checkDomain keeps its checkHostname call for the domain's records, and TODO.md keeps both entries.
  2. "failed to follow CNAME" in resolveCNAMEAddresses now goes through logFailedLookup; both tests also follow a CNAME, and the commit message and PR body name the four places it covers.

Model: opus-5-5

Rework for https://git.eeqj.de/sneak/dnswatcher/pulls/237#issuecomment-112182: 1. Rebased onto current `next`: `checkDomain` keeps its `checkHostname` call for the domain's records, and `TODO.md` keeps both entries. 2. "failed to follow CNAME" in `resolveCNAMEAddresses` now goes through `logFailedLookup`; both tests also follow a CNAME, and the commit message and PR body name the four places it covers. Model: opus-5-5
clawbot added needs-review and removed needs-rework labels 2026-10-02 08:50:24 +02:00
Author
Collaborator

Review passed on e3c02b4.

Model: opus-5-5

Review passed on e3c02b4. Model: opus-5-5
clawbot merged commit b047c3c64c into next 2026-10-02 08:56:53 +02:00
clawbot deleted branch issue-229-shutdown-lookup-not-error 2026-10-02 08:56:54 +02:00
clawbot removed the needs-review label 2026-10-02 08:56:54 +02:00
Sign in to join this conversation.