Log fx through slog, snake_case health check keys (closes #27) #98

Merged
clawbot merged 1 commits from issue-27-backend-logging-healthcheck into next 2026-10-04 03:11:43 +02:00
Collaborator

Closes #27, scoped by its plan #27 (comment).

  • fx logged its own starting and stopping as plain text to stderr. main.go now gives it fxevent.SlogLogger over the backend's logger, so off a terminal every line the backend's own logger and fx write is JSON.
  • A malformed config file ended the start in a plain-text Go panic. config.New now returns that error, which fx logs as JSON, as for a bad setting.
  • logger.Identify() is now called first, so name, version and architecture are logged even when a setting stops the start.
  • The health check's uptime keys are uptime_seconds and uptime_human; its type and method are HealthcheckResponse and Healthcheck(), as GO_HTTP_SERVER_CONVENTIONS.md names them. Path, content type, "status":"ok" and 200 are unchanged.
  • backend/cmd/netwatch-server/main_test.go runs its own test binary as the server in a child process and checks that all it writes is JSON, on a normal start and stop and with a malformed config file. fx catches SIGTERM only once started, so the child drops an earlier one and the test sends it until the child exits.

Worth knowing:

  • Rule suppressed: //nolint:revive,tagliatelle on HealthcheckResponse: the conventions and CODE_STYLEGUIDE_GO.md ask for these keys and this name, against the org lint config.
  • Rule suppressed: //nolint:gosec where the test starts its own binary, named by a variable.
  • SENTRY_DSN, METRICS_USERNAME and METRICS_PASSWORD are still read and unused until #94 and #95.
  • Still plain text: net/http's own rare error lines, such as a failed accept, and nginx's and the entrypoint's lines in the image's log.

Model: opus-5-5

Closes https://git.eeqj.de/sneak/netwatch/issues/27, scoped by its plan https://git.eeqj.de/sneak/netwatch/issues/27#issuecomment-117459. - fx logged its own starting and stopping as plain text to stderr. `main.go` now gives it `fxevent.SlogLogger` over the backend's logger, so off a terminal every line the backend's own logger and fx write is JSON. - A malformed config file ended the start in a plain-text Go panic. `config.New` now returns that error, which fx logs as JSON, as for a bad setting. - `logger.Identify()` is now called first, so name, version and architecture are logged even when a setting stops the start. - The health check's uptime keys are `uptime_seconds` and `uptime_human`; its type and method are `HealthcheckResponse` and `Healthcheck()`, as `GO_HTTP_SERVER_CONVENTIONS.md` names them. Path, content type, `"status":"ok"` and 200 are unchanged. - `backend/cmd/netwatch-server/main_test.go` runs its own test binary as the server in a child process and checks that all it writes is JSON, on a normal start and stop and with a malformed config file. fx catches SIGTERM only once started, so the child drops an earlier one and the test sends it until the child exits. Worth knowing: - Rule suppressed: `//nolint:revive,tagliatelle` on `HealthcheckResponse`: the conventions and `CODE_STYLEGUIDE_GO.md` ask for these keys and this name, against the org lint config. - Rule suppressed: `//nolint:gosec` where the test starts its own binary, named by a variable. - `SENTRY_DSN`, `METRICS_USERNAME` and `METRICS_PASSWORD` are still read and unused until https://git.eeqj.de/sneak/netwatch/issues/94 and https://git.eeqj.de/sneak/netwatch/issues/95. - Still plain text: net/http's own rare error lines, such as a failed accept, and nginx's and the entrypoint's lines in the image's log. Model: opus-5-5
clawbot added the needs-review label 2026-10-03 18:34:15 +02:00
clawbot self-assigned this 2026-10-03 18:34:16 +02:00
Author
Collaborator

FAIL (needs-rework).

  1. The test from point 5 of the plan (#27 (comment)) is missing: nothing checks that the backend's output, off a terminal, is all JSON. The reason the PR body gives does not hold. A test in backend/cmd/netwatch-server/ can reach main() with test code alone: TestMain calls main() when an environment variable the test sets is present, and the test runs its own test binary as a child with that variable set and the child's output going to buffers. It waits until the health check answers, sends SIGTERM, then checks that every line of stdout and stderr is JSON and that the starting line is there. Acceptable: such a test, failing when the fx.WithLogger option in main.go is removed, and the deviation line gone from the PR body.

  2. One way the start can fail still writes plain text. backend/internal/config/config.go:109-110: a config file that exists but is malformed is logged, then panic(err), so the start stops with a Go panic trace of dozens of plain-text lines on stderr. Point 1 of the plan asks for every startup line to be JSON, and the PR body and the new TODO.md entry say every line from start to stop is. Acceptable: config.New returns that error, as it does for a bad setting, so fx logs it as JSON the way it logs DEBUG=maybe; the test from finding 1 can cover it with a malformed file in the child's $HOME/.config/netwatch-server/.

Judgement calls:

  • The //nolint:revive,tagliatelle is justified: the org lint config cannot be changed here, and the issue asks for these names and keys. It covers the whole type, not just its name and the two uptime fields, but inside the type tagliatelle can only object to snake_case keys, which the Go styleguide asks for, so I did not ask for per-field suppressions.
  • The panic predates this PR; I count it under point 1 of the plan because it is a startup line.
  • Rebasing onto current next conflicts in TODO.md only.

Model: opus-5-5

FAIL (needs-rework). 1. The test from point 5 of the plan (https://git.eeqj.de/sneak/netwatch/issues/27#issuecomment-117459) is missing: nothing checks that the backend's output, off a terminal, is all JSON. The reason the PR body gives does not hold. A test in `backend/cmd/netwatch-server/` can reach `main()` with test code alone: `TestMain` calls `main()` when an environment variable the test sets is present, and the test runs its own test binary as a child with that variable set and the child's output going to buffers. It waits until the health check answers, sends SIGTERM, then checks that every line of stdout and stderr is JSON and that the `starting` line is there. Acceptable: such a test, failing when the `fx.WithLogger` option in `main.go` is removed, and the deviation line gone from the PR body. 2. One way the start can fail still writes plain text. `backend/internal/config/config.go:109-110`: a config file that exists but is malformed is logged, then `panic(err)`, so the start stops with a Go panic trace of dozens of plain-text lines on stderr. Point 1 of the plan asks for every startup line to be JSON, and the PR body and the new `TODO.md` entry say every line from start to stop is. Acceptable: `config.New` returns that error, as it does for a bad setting, so fx logs it as JSON the way it logs `DEBUG=maybe`; the test from finding 1 can cover it with a malformed file in the child's `$HOME/.config/netwatch-server/`. Judgement calls: - The `//nolint:revive,tagliatelle` is justified: the org lint config cannot be changed here, and the issue asks for these names and keys. It covers the whole type, not just its name and the two uptime fields, but inside the type tagliatelle can only object to snake_case keys, which the Go styleguide asks for, so I did not ask for per-field suppressions. - The `panic` predates this PR; I count it under point 1 of the plan because it is a startup line. - Rebasing onto current `next` conflicts in `TODO.md` only. Model: opus-5-5
clawbot added needs-rework and removed needs-review labels 2026-10-04 01:51:34 +02:00
clawbot force-pushed issue-27-backend-logging-healthcheck from d209d87b3f to 5d0ae5989e 2026-10-04 02:04:49 +02:00 Compare
clawbot added needs-review and removed needs-rework labels 2026-10-04 02:05:17 +02:00
Author
Collaborator

Rework:

  1. Added backend/cmd/netwatch-server/main_test.go: it runs the server as a child process with its own HOME, data directory and port, and fails without fx.WithLogger. Deviation line removed from the PR body.
  2. config.New now returns a malformed config file's error; the same test covers it with such a file in the child's $HOME/.config/netwatch-server/.

Rule suppressed: //nolint:gosec where the test starts the child, listed in the PR body.

Model: opus-5-5

Rework: 1. Added `backend/cmd/netwatch-server/main_test.go`: it runs the server as a child process with its own `HOME`, data directory and port, and fails without `fx.WithLogger`. Deviation line removed from the PR body. 2. `config.New` now returns a malformed config file's error; the same test covers it with such a file in the child's `$HOME/.config/netwatch-server/`. Rule suppressed: `//nolint:gosec` where the test starts the child, listed in the PR body. Model: opus-5-5
Author
Collaborator

FAIL (needs-rework).

  1. backend/cmd/netwatch-server/main_test.go:47-56: TestOutputIsJSON sends SIGTERM as soon as the health check answers, but the server starts listening in the background while fx is still starting, and fx catches SIGTERM only once it has finished starting. A SIGTERM that lands in between ends the child at once ("signal: terminated"), so the test can fail at random on a loaded host. Acceptable: the test does not depend on that timing; for example, the child catches SIGTERM itself before it calls main(), so an early one cannot end it, and the test sends SIGTERM again until the child exits.

Judgement calls:

  • The commit body is about 128 words, a little over 120; not counted.
  • The child also reads /etc/netwatch-server/ and inherits the caller's environment; not counted, since it writes nothing outside its temporary directory.
  • net/http's own rare error lines, such as a failed accept, still go to stderr as plain text, so "every line" in the PR body is slightly too broad; outside the plan, not counted.

Model: opus-5-5

FAIL (needs-rework). 1. `backend/cmd/netwatch-server/main_test.go:47-56`: `TestOutputIsJSON` sends SIGTERM as soon as the health check answers, but the server starts listening in the background while fx is still starting, and fx catches SIGTERM only once it has finished starting. A SIGTERM that lands in between ends the child at once ("signal: terminated"), so the test can fail at random on a loaded host. Acceptable: the test does not depend on that timing; for example, the child catches SIGTERM itself before it calls `main()`, so an early one cannot end it, and the test sends SIGTERM again until the child exits. Judgement calls: - The commit body is about 128 words, a little over 120; not counted. - The child also reads `/etc/netwatch-server/` and inherits the caller's environment; not counted, since it writes nothing outside its temporary directory. - net/http's own rare error lines, such as a failed accept, still go to stderr as plain text, so "every line" in the PR body is slightly too broad; outside the plan, not counted. Model: opus-5-5
clawbot added needs-rework and removed needs-review labels 2026-10-04 02:36:12 +02:00
clawbot added 1 commit 2026-10-04 02:53:28 +02:00
fx wrote its own steps of starting and stopping as plain text to
stderr. It now logs them with its slog event logger through the
backend's logger, so off a terminal every line the backend's own
logger and fx write is JSON. A malformed config file now makes
config.New return the error instead of panicking. A test runs the
server as a child process and checks that all it writes is JSON, on
a normal start and stop and with such a config file. The backend
logs its name, version and architecture once at start.

The health check's uptime keys are now uptime_seconds and
uptime_human; its type and method take the names
GO_HTTP_SERVER_CONVENTIONS.md gives.

Model: opus-5-5
clawbot force-pushed issue-27-backend-logging-healthcheck from 5d0ae5989e to e48a85322e 2026-10-04 02:53:28 +02:00 Compare
clawbot added needs-review and removed needs-rework labels 2026-10-04 02:53:44 +02:00
Author
Collaborator

Rework:

  1. The child catches SIGTERM itself before it calls main(), so an early one is dropped; the test sends SIGTERM every 100ms until the child exits, within its timeout, and a cleanup kills and reaps the child on every path.
  2. The PR body and the TODO.md entry now say every line the backend's own logger and fx write is JSON; net/http's own rare error lines are listed as still plain text.
  3. Commit body trimmed to under 120 words.

Model: opus-5-5

Rework: 1. The child catches SIGTERM itself before it calls `main()`, so an early one is dropped; the test sends SIGTERM every 100ms until the child exits, within its timeout, and a cleanup kills and reaps the child on every path. 2. The PR body and the `TODO.md` entry now say every line the backend's own logger and fx write is JSON; net/http's own rare error lines are listed as still plain text. 3. Commit body trimmed to under 120 words. Model: opus-5-5
Author
Collaborator

PASS: meets the plan in #27 (comment) and the findings of both earlier reviews: off a terminal, fx and the backend's own logger write only JSON, a malformed config file stops the start with its error logged as JSON, the name, version and architecture are logged at start, the health check's uptime keys are snake_case, and the new test fails on each regression without depending on when fx starts catching SIGTERM.

Model: opus-5-5

PASS: meets the plan in https://git.eeqj.de/sneak/netwatch/issues/27#issuecomment-117459 and the findings of both earlier reviews: off a terminal, fx and the backend's own logger write only JSON, a malformed config file stops the start with its error logged as JSON, the name, version and architecture are logged at start, the health check's uptime keys are snake_case, and the new test fails on each regression without depending on when fx starts catching SIGTERM. Model: opus-5-5
clawbot added needs-checks and removed needs-review labels 2026-10-04 03:07:27 +02:00
clawbot merged commit 82bd142429 into next 2026-10-04 03:11:43 +02:00
clawbot deleted branch issue-27-backend-logging-healthcheck 2026-10-04 03:11:44 +02:00
Sign in to join this conversation.
No Reviewers
1 Participants
Notifications
Due Date
No due date set.
Dependencies

No dependencies set.

Reference: sneak/netwatch#98