log: write durations as text, not nanoseconds (closes #228)

The JSON log wrote a Go duration as a bare count of nanoseconds, so
the watcher starting line showed dnsInterval 120000000000 for 2m and a
delivery retry showed retryIn 1015437050. Each duration logged is now
passed through its String() form: dnsInterval and tlsInterval when the
watcher starts, retryIn on a delivery retry, and latency on a
succeeded port check. A test checks that retryIn is logged as the
text of the wait the retry actually took.

The request log's latency_ms is left as it is: its key names its
unit.

Model: opus-5-5

TODO.md

@@ -19,6 +19,8 @@ trial run of the finished image: https://git.eeqj.de/sneak/dnswatcher/issues/149
 
 # Completed Steps
 
+- 2026-10-02: durations in the log are written as text such as `2m0s`, not as a
+  bare count of nanoseconds (closes #228).
 - 2026-10-02: a resolver test that reads one record type from a nameserver's
   answer asks again when that type is missing from it (closes #218).
 - 2026-10-02: a plain `docker build .` of a clone stamps its tag or short

internal/notify/retry.go

@@ -115,7 +115,9 @@ func (svc *Service) deliverWithRetry(
 			"endpoint", endpoint,
 			"attempt", attempt+1,
 			"maxAttempts", cfg.MaxRetries+1,
-			"retryIn", delay,
+			// As text: the JSON log writes a time.Duration as
+			// bare nanoseconds.
+			"retryIn", delay.String(),
 			"error", lastErr,
 		)
 

internal/notify/retry_test.go

@@ -2,6 +2,7 @@ package notify_test
 
 import (
 	"context"
+	"encoding/json"
 	"errors"
 	"net/http"
 	"net/http/httptest"
@@ -189,6 +190,50 @@ func TestDeliverWithRetryExhaustsAttempts(t *testing.T) {
 	}
 }
 
+// TestDeliverWithRetryLogsRetryInAsText checks that the wait
+// before a retry is logged as text such as "1.02s", not as a
+// count of nanoseconds.
+func TestDeliverWithRetryLogsRetryInAsText(t *testing.T) {
+	t.Parallel()
+
+	svc, logs := newLoggingService(http.DefaultTransport)
+	svc.SetRetryConfig(notify.RetryConfig{
+		MaxRetries: 1,
+		BaseDelay:  time.Second,
+		MaxDelay:   time.Second,
+	})
+
+	var waited time.Duration
+
+	svc.SetSleepFunc(func(d time.Duration) <-chan time.Time {
+		waited = d
+
+		return instantSleep(d)
+	})
+
+	_ = svc.DeliverWithRetry(
+		context.Background(), "test",
+		func(_ context.Context) error {
+			return errFail
+		},
+	)
+
+	// With one retry, only the first failure is logged.
+	var record map[string]any
+
+	err := json.Unmarshal([]byte(logs.String()), &record)
+	if err != nil {
+		t.Fatalf("log is not one JSON record: %v\n%s", err, logs)
+	}
+
+	if record["retryIn"] != waited.String() {
+		t.Errorf(
+			"retryIn logged as %v, want %q",
+			record["retryIn"], waited.String(),
+		)
+	}
+}
+
 func TestDeliverWithRetryRespectsContextCancellation(
 	t *testing.T,
 ) {

internal/portcheck/portcheck.go

@@ -193,7 +193,9 @@ func (c *Checker) checkConnection(
 	c.log.Debug(
 		"port check succeeded",
 		"target", target,
-		"latency", latency,
+		// As text: the JSON log writes a time.Duration as bare
+		// nanoseconds.
+		"latency", latency.String(),
 	)
 
 	return &PortResult{

internal/watcher/watcher.go

@@ -123,8 +123,10 @@ func (w *Watcher) Run(ctx context.Context) {
 		"watcher starting",
 		"domains", len(w.config.Domains),
 		"hostnames", len(w.config.Hostnames),
-		"dnsInterval", w.config.DNSInterval,
+		// As text: the JSON log writes a time.Duration as bare
-		"tlsInterval", w.config.TLSInterval,
+		// nanoseconds.
+		"dnsInterval", w.config.DNSInterval.String(),
+		"tlsInterval", w.config.TLSInterval.String(),
 	)
 
 	w.RunOnce(ctx)