Server 2.6.2: log update checks and downloads; Go 1.27.3

The update relay logs every check (car, number of releases, newest
pre-release) and every download (car, file, size, then bytes and time,
or that it was cut short); never the forge's address or token, tested.
Go 1.27.3 for the build image and toolchain: govulncheck had found
GO-2026-6809 in crypto/x509 under 1.26.9; source and binary now clean.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01LhzAVaUyqcw5PkGjz4mWW6

server/Dockerfile

@@ -1,7 +1,7 @@
 # The car server: one static Go binary on distroless, running as non-root.
 # Configuration comes from the environment at runtime; nothing secret is baked in.
 
-FROM docker.io/library/golang:1.26.9-alpine AS build
+FROM docker.io/library/golang:1.27.3-alpine AS build
 WORKDIR /src
 ENV CGO_ENABLED=0 GOFLAGS=-trimpath GOTOOLCHAIN=local
 COPY go.mod go.sum ./

server/README.md

@@ -52,6 +52,11 @@ with download URLs pointing back at this server, and their attachments streamed
 repository stays private and the forge token never reaches the car; redirects away from the
 forge are not followed. The car verifies everything itself (`OTA.md`). 404 when unset.
 
+Each check and each download is logged with the car's installation ID ("shared token" for the
+shared ingest token): `update check` (how many releases, the newest pre-release), `update
+download started` (file, size), then `update handed out` (bytes sent, time taken) or `update
+download cut short`. The forge's address and token never appear in the log.
+
 ## Settings from a phone
 
 The ABRP credentials are long to type on the car. With pairing on, the car (with its own token)

server/go.mod

@@ -2,7 +2,7 @@ module git.stinnesbeck.com/nils/mg4/server
 
 go 1.26.0
 
-toolchain go1.26.9
+toolchain go1.27.3
 
 require github.com/influxdata/influxdb-client-go/v2 v2.14.0
 

server/releases.go

@@ -113,8 +113,17 @@ func (a *API) releasesOff(w http.ResponseWriter) bool {
 	return true
 }
 
-func (a *API) appReleases(w http.ResponseWriter, r *http.Request, _ caller, _ []byte) error {
+// who names the car in the update log: its installation ID, or the shared ingest token.
+func who(c caller) string {
+	if c.installationID == "" {
+		return "shared token"
+	}
+	return c.installationID
+}
+
+func (a *API) appReleases(w http.ResponseWriter, r *http.Request, c caller, _ []byte) error {
 	if a.releasesOff(w) {
+		slog.Info("update check while app updates are off", "installation", who(c))
 		return nil
 	}
 	resp, err := a.Releases.get(r.Context(), "/api/v1/repos/"+a.Releases.Repo+"/releases?limit=20")
@@ -123,7 +132,7 @@ func (a *API) appReleases(w http.ResponseWriter, r *http.Request, _ caller, _ []
 	}
 	defer resp.Body.Close()
 	if resp.StatusCode != http.StatusOK {
-		slog.Warn("forge refused the release list", "status", resp.StatusCode)
+		slog.Warn("forge refused the release list", "installation", who(c), "status", resp.StatusCode)
 		writeJSON(w, http.StatusBadGateway, map[string]string{"error": "the forge did not answer"})
 		return nil
 	}
@@ -133,8 +142,13 @@ func (a *API) appReleases(w http.ResponseWriter, r *http.Request, _ caller, _ []
 	}
 	base := a.publicURL(r) + "/v1/app/assets/"
 	out := make([]carRelease, 0, len(releases))
+	newest := "none"
 	for _, rel := range releases {
 		cr := carRelease{TagName: rel.TagName, Prerelease: rel.Prerelease, Draft: rel.Draft, Assets: []carAsset{}}
+		// The forge lists the newest first; the car takes pre-releases only.
+		if newest == "none" && rel.Prerelease && !rel.Draft {
+			newest = rel.TagName
+		}
 		for _, as := range rel.Assets {
 			cr.Assets = append(cr.Assets, carAsset{Name: as.Name, Size: as.Size,
 				BrowserDownloadURL: base + strconv.FormatInt(rel.ID, 10) + "/" + strconv.FormatInt(as.ID, 10) +
@@ -142,13 +156,14 @@ func (a *API) appReleases(w http.ResponseWriter, r *http.Request, _ caller, _ []
 		}
 		out = append(out, cr)
 	}
+	slog.Info("update check", "installation", who(c), "releases", len(out), "newest", newest)
 	writeJSON(w, http.StatusOK, out)
 	return nil
 }
 
 // appAsset streams one release attachment. The forge's own metadata names the file, so a car
 // cannot ask for anything but an attachment of this repository's releases.
-func (a *API) appAsset(w http.ResponseWriter, r *http.Request, _ caller, _ []byte) error {
+func (a *API) appAsset(w http.ResponseWriter, r *http.Request, c caller, _ []byte) error {
 	if a.releasesOff(w) {
 		return nil
 	}
@@ -173,7 +188,7 @@ func (a *API) appAsset(w http.ResponseWriter, r *http.Request, _ caller, _ []byt
 		return nil
 	}
 	if meta.StatusCode != http.StatusOK || decodeErr != nil || asset.UUID == "" {
-		slog.Warn("forge refused the asset", "status", meta.StatusCode)
+		slog.Warn("forge refused the asset", "installation", who(c), "status", meta.StatusCode)
 		writeJSON(w, http.StatusBadGateway, map[string]string{"error": "the forge did not answer"})
 		return nil
 	}
@@ -187,7 +202,7 @@ func (a *API) appAsset(w http.ResponseWriter, r *http.Request, _ caller, _ []byt
 	}
 	defer file.Body.Close()
 	if file.StatusCode != http.StatusOK {
-		slog.Warn("forge refused the download", "status", file.StatusCode)
+		slog.Warn("forge refused the download", "installation", who(c), "asset", asset.Name, "status", file.StatusCode)
 		writeJSON(w, http.StatusBadGateway, map[string]string{"error": "the forge did not answer"})
 		return nil
 	}
@@ -201,9 +216,17 @@ func (a *API) appAsset(w http.ResponseWriter, r *http.Request, _ caller, _ []byt
 	if file.ContentLength > 0 && file.ContentLength <= maxAssetBytes {
 		h.Set("Content-Length", strconv.FormatInt(file.ContentLength, 10))
 	}
+	slog.Info("update download started", "installation", who(c), "asset", asset.Name,
+		"bytes", file.ContentLength)
+	started := time.Now()
 	w.WriteHeader(http.StatusOK)
-	if _, err := io.Copy(w, io.LimitReader(file.Body, maxAssetBytes)); err != nil {
-		slog.Warn("asset transfer cut short", "asset", asset.Name, "error", err)
+	sent, err := io.Copy(w, io.LimitReader(file.Body, maxAssetBytes))
+	took := time.Since(started).Round(time.Millisecond)
+	if err != nil {
+		slog.Warn("update download cut short", "installation", who(c), "asset", asset.Name,
+			"sent", sent, "took", took, "error", err)
+		return nil
 	}
+	slog.Info("update handed out", "installation", who(c), "asset", asset.Name, "sent", sent, "took", took)
 	return nil
 }

server/releases_test.go

@@ -1,7 +1,9 @@
 package main
 
 import (
+	"bytes"
 	"encoding/json"
+	"log/slog"
 	"net/http"
 	"net/http/httptest"
 	"strings"
@@ -113,3 +115,36 @@ func TestForgeURLMustBeHTTPS(t *testing.T) {
 		t.Fatal("plain http forge accepted")
 	}
 }
+
+// The server's log says who checked for and fetched an update, and how it went — the car's
+// installation (here the shared token), the newest pre-release, the file and the bytes — and
+// never the forge's token or address.
+func TestUpdatesAreLogged(t *testing.T) {
+	var logged bytes.Buffer
+	previous := slog.Default()
+	slog.SetDefault(slog.New(slog.NewTextHandler(&logged, nil)))
+	defer slog.SetDefault(previous)
+
+	forge := fakeForge(t)
+	defer forge.Close()
+	h := releasesAPI(t, forge)
+	if rec := do(t, h, "GET", "/v1/app/releases", testToken, ""); rec.Code != 200 {
+		t.Fatalf("%d", rec.Code)
+	}
+	if rec := do(t, h, "GET", "/v1/app/assets/7/11/NilsMG4-unstable-2.16.0.apk", testToken, ""); rec.Code != 200 {
+		t.Fatalf("%d", rec.Code)
+	}
+	out := logged.String()
+	for _, want := range []string{
+		`msg="update check" installation="shared token" releases=1 newest=car-2.16.0`,
+		`msg="update download started" installation="shared token" asset=NilsMG4-unstable-2.16.0.apk`,
+		`msg="update handed out" installation="shared token" asset=NilsMG4-unstable-2.16.0.apk sent=4`,
+	} {
+		if !strings.Contains(out, want) {
+			t.Errorf("log lacks %q:\n%s", want, out)
+		}
+	}
+	if strings.Contains(out, testForgeToken) || strings.Contains(out, forge.URL) {
+		t.Fatal("the forge or its token leaked into the log")
+	}
+}