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

Merged
clawbot merged 1 commits from issue-228-log-durations-readable into next 2026-10-02 08:37:48 +02:00
Collaborator

Closes #228

The JSON log wrote every Go duration as a bare count of nanoseconds. Each duration that is logged now goes through its String() form, so the log reads "dnsInterval":"2m0s" and "retryIn":"1.249852478s":

  • dnsInterval and tlsInterval on the watcher starting line
  • retryIn when a notification delivery is retried
  • latency on the debug line for a port check that succeeded

A new test in internal/notify/retry_test.go checks that retryIn is logged as the text of the wait the retry actually took.

When standard output is a terminal the log is plain text, which already wrote durations this way; that output does not change.

Judgement call: the request log's latency_ms stays a whole number of milliseconds, since its key names its unit.
Judgement call: retryIn keeps full precision (1.249852478s) rather than being rounded to milliseconds as in the issue's example.

Model: opus-5-5

Closes https://git.eeqj.de/sneak/dnswatcher/issues/228 The JSON log wrote every Go duration as a bare count of nanoseconds. Each duration that is logged now goes through its `String()` form, so the log reads `"dnsInterval":"2m0s"` and `"retryIn":"1.249852478s"`: - `dnsInterval` and `tlsInterval` on the `watcher starting` line - `retryIn` when a notification delivery is retried - `latency` on the debug line for a port check that succeeded A new test in `internal/notify/retry_test.go` checks that `retryIn` is logged as the text of the wait the retry actually took. When standard output is a terminal the log is plain text, which already wrote durations this way; that output does not change. Judgement call: the request log's `latency_ms` stays a whole number of milliseconds, since its key names its unit. Judgement call: `retryIn` keeps full precision (`1.249852478s`) rather than being rounded to milliseconds as in the issue's example. Model: opus-5-5
clawbot added the needs-review label 2026-10-02 08:14:43 +02:00
clawbot self-assigned this 2026-10-02 08:14:43 +02:00
Author
Collaborator

Review passed on 445ff54.

Model: opus-5-5

Review passed on 445ff54. Model: opus-5-5
clawbot added 1 commit 2026-10-02 08:37:15 +02:00
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
clawbot force-pushed issue-228-log-durations-readable from 445ff54152 to 68c3c66061 2026-10-02 08:37:15 +02:00 Compare
clawbot merged commit ceb24c5004 into next 2026-10-02 08:37:48 +02:00
clawbot deleted branch issue-228-log-durations-readable 2026-10-02 08:37:48 +02:00
clawbot removed the needs-review label 2026-10-02 08:37:48 +02:00
Sign in to join this conversation.