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

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
2026-10-04 00:52:14 +00:00
parent 924527b744
commit e48a85322e
7 changed files with 276 additions and 21 deletions
@@ -0,0 +1,227 @@
+package main
+
+import (
+	"bytes"
+	"context"
+	"encoding/json"
+	"net"
+	"net/http"
+	"os"
+	"os/exec"
+	"os/signal"
+	"path/filepath"
+	"strings"
+	"syscall"
+	"testing"
+	"time"
+)
+
+// The tests run main() in a child process, this test binary started
+// again with runMainEnv set, because main() can exit its process and
+// takes its settings from the environment.
+const runMainEnv = "NETWATCH_SERVER_RUN_MAIN"
+
+// childTimeout bounds each child's whole run; it is killed after it.
+const childTimeout = 10 * time.Second
+
+func TestMain(m *testing.M) {
+	if os.Getenv(runMainEnv) != "" {
+		// A SIGTERM that comes before fx catches it is dropped, not fatal.
+		signal.Notify(make(chan os.Signal, 1), syscall.SIGTERM)
+		main()
+
+		return
+	}
+
+	os.Exit(m.Run())
+}
+
+// TestOutputIsJSON: off a terminal, every line the server writes from
+// start to stop is JSON, fx's own lines included.
+func TestOutputIsJSON(t *testing.T) {
+	t.Parallel()
+
+	ctx, cancel := context.WithTimeout(t.Context(), childTimeout)
+	defer cancel()
+
+	port := freePort(ctx, t)
+	child, stdout, stderr := startServer(ctx, t, t.TempDir(), port)
+
+	waitForHealthcheck(ctx, t, port)
+
+	// The child drops a SIGTERM that comes before fx catches it (see
+	// TestMain), so send one every 100ms until the test ends. ctx
+	// bounds the wait: when it ends, the child is killed.
+	stop := make(chan struct{})
+	defer close(stop)
+
+	go func() {
+		for {
+			_ = child.Process.Signal(syscall.SIGTERM)
+
+			select {
+			case <-stop:
+				return
+			case <-time.After(100 * time.Millisecond):
+			}
+		}
+	}()
+
+	err := child.Wait()
+	if err != nil {
+		t.Fatalf("server exit = %v, want success", err)
+	}
+
+	requireJSONLines(t, stdout, stderr)
+
+	if !strings.Contains(stdout.String(), `"msg":"starting"`) {
+		t.Fatalf("no startup line in stdout:\n%s", stdout)
+	}
+}
+
+// TestMalformedConfigFileStopsTheStart: a config file the server finds
+// but cannot read stops the start, and the error is logged as JSON.
+func TestMalformedConfigFileStopsTheStart(t *testing.T) {
+	t.Parallel()
+
+	ctx, cancel := context.WithTimeout(t.Context(), childTimeout)
+	defer cancel()
+
+	home := t.TempDir()
+	dir := filepath.Join(home, ".config", "netwatch-server")
+
+	err := os.MkdirAll(dir, 0o750)
+	if err != nil {
+		t.Fatal(err)
+	}
+
+	err = os.WriteFile(filepath.Join(dir, "netwatch-server.yaml"),
+		[]byte("PORT: [8080\n"), 0o600)
+	if err != nil {
+		t.Fatal(err)
+	}
+
+	child, stdout, stderr := startServer(ctx, t, home, freePort(ctx, t))
+
+	err = child.Wait()
+	if child.ProcessState.ExitCode() != 1 {
+		t.Fatalf("server exit = %v, want exit status 1", err)
+	}
+
+	requireJSONLines(t, stdout, stderr)
+
+	if !strings.Contains(stdout.String(), "netwatch-server.yaml") {
+		t.Fatalf("no error naming the config file in stdout:\n%s", stdout)
+	}
+}
+
+// startServer runs main() in a child process listening on
+// 127.0.0.1:port, with home as its HOME and working directory and its
+// data directory in home, so it touches nothing outside home. Its
+// stdout and stderr go to the two buffers returned, which hold all of
+// it once child.Wait returns. The child is killed when ctx ends, and
+// killed and reaped when the test ends if nothing waited for it.
+func startServer(
+	ctx context.Context,
+	t *testing.T,
+	home, port string,
+) (*exec.Cmd, *bytes.Buffer, *bytes.Buffer) {
+	t.Helper()
+
+	self, err := os.Executable()
+	if err != nil {
+		t.Fatal(err)
+	}
+
+	var stdout, stderr bytes.Buffer
+
+	child := exec.CommandContext(ctx, self) //nolint:gosec // this test binary
+	child.Dir = home
+	child.Env = append(os.Environ(),
+		runMainEnv+"=1",
+		"HOME="+home,
+		"DATA_DIR="+filepath.Join(home, "data"),
+		"BIND_ADDRESS=127.0.0.1",
+		"PORT="+port,
+	)
+	child.Stdout = &stdout
+	child.Stderr = &stderr
+
+	err = child.Start()
+	if err != nil {
+		t.Fatal(err)
+	}
+
+	t.Cleanup(func() {
+		if child.ProcessState == nil {
+			_ = child.Process.Kill()
+			_ = child.Wait()
+		}
+	})
+
+	return child, &stdout, &stderr
+}
+
+// freePort returns a TCP port on 127.0.0.1 that was free a moment ago.
+func freePort(ctx context.Context, t *testing.T) string {
+	t.Helper()
+
+	var lc net.ListenConfig
+
+	l, err := lc.Listen(ctx, "tcp", "127.0.0.1:0")
+	if err != nil {
+		t.Fatal(err)
+	}
+
+	_ = l.Close()
+
+	_, port, err := net.SplitHostPort(l.Addr().String())
+	if err != nil {
+		t.Fatal(err)
+	}
+
+	return port
+}
+
+// waitForHealthcheck returns once the health check on port answers 200.
+func waitForHealthcheck(ctx context.Context, t *testing.T, port string) {
+	t.Helper()
+
+	url := "http://127.0.0.1:" + port + "/.well-known/healthcheck"
+
+	for {
+		req, err := http.NewRequestWithContext(ctx, http.MethodGet, url, nil)
+		if err != nil {
+			t.Fatal(err)
+		}
+
+		resp, err := http.DefaultClient.Do(req)
+		if err == nil {
+			_ = resp.Body.Close()
+
+			if resp.StatusCode == http.StatusOK {
+				return
+			}
+		}
+
+		select {
+		case <-ctx.Done():
+			t.Fatalf("health check never answered: %v", err)
+		case <-time.After(50 * time.Millisecond):
+		}
+	}
+}
+
+// requireJSONLines fails the test on each line of outs that is not
+// JSON.
+func requireJSONLines(t *testing.T, outs ...*bytes.Buffer) {
+	t.Helper()
+
+	for _, out := range outs {
+		for line := range strings.Lines(out.String()) {
+			if !json.Valid([]byte(line)) {
+				t.Errorf("line is not JSON: %s", line)
+			}
+		}
+	}
+}