egress: close the remaining ways an endpoint or address reaches a log

Round two on #417.

redactEndpoint returned hostless values verbatim. url.Parse accepts
"secret" and "http:token" without error, and clearing User does nothing
to an opaque string, so a bare credential configured as the endpoint
would have been echoed whole. Refused now, same rule sanitizeReportURL
already used.

The exporter-construction failure logged err directly, and an endpoint
parse failure is exactly the error that quotes the endpoint back — with
its credentials. The endpoint is substituted with its redacted form
rather than dropped, so the diagnostic survives.

The version line was emitted before instrument creation and
RegisterCallback, both of which return through shutdownAfter, so it
announced success for setup that could still fail. Moved to immediately
before the successful return, still after enableOTELLogs.

peerAttrs' doc comment had a stale paragraph explaining why remote_addr
and forwarded_for were both logged, directly above the new paragraph
explaining why neither is. A doc that promises address logging and
denies it in the same breath is worse than either. Rewritten as one
contract.

Three tests added for things previously assertable only by inspection:
the endpoint-redaction table including query, fragment and hostless
cases; the enabled-path announcement against an httptest OTLP receiver
with credentials in the endpoint; and the startup version line through
the real initMetrics path, which the metrics tests miss because they stub
initMetricsFn. Each verified against a mutation.

Also corrected a comment of mine that said the enabled line is exported.
It is emitted before the handler swap, so it is journal-only — which is
deliberate, since a line reporting whether export works should not be
routed through the exporter it describes.

Author: Adam Fisk

egress/egresslib_test.go

@@ -1,11 +1,16 @@
 package egress
 
 import (
+	"bytes"
 	"context"
 	"crypto/tls"
+	"log/slog"
 	"net"
+	"strings"
 	"testing"
 	"time"
+
+	"github.com/getlantern/broflake/common"
 )
 
 // TestNewListener_CleanShutdownDoesNotPanic is a regression test for the
@@ -53,3 +58,44 @@ func TestNewListener_CleanShutdownDoesNotPanic(t *testing.T) {
 	// machine and doesn't meaningfully slow down the test suite.
 	time.Sleep(100 * time.Millisecond)
 }
+
+// The startup version line is the only thing that says which build is running:
+// the spans carry no service.version, so before this the answer lived on the
+// host. Asserted through the real initMetrics path — the metrics tests stub
+// initMetricsFn and the OTLP tests call enableOTELLogs directly, so neither
+// would notice this line disappearing.
+func TestNewListener_LogsTheRunningVersion(t *testing.T) {
+	// No collector configured, so enableOTELLogs no-ops and this exercises the
+	// version line alone rather than standing up an exporter.
+	t.Setenv("OTEL_EXPORTER_OTLP_ENDPOINT", "")
+	t.Setenv("OTEL_EXPORTER_OTLP_LOGS_ENDPOINT", "")
+
+	var buf bytes.Buffer
+	prev := slog.Default()
+	slog.SetDefault(slog.New(slog.NewTextHandler(&buf, &slog.HandlerOptions{Level: slog.LevelDebug})))
+	t.Cleanup(func() { slog.SetDefault(prev) })
+
+	tcpL, err := net.Listen("tcp", "127.0.0.1:0")
+	if err != nil {
+		t.Fatalf("listen: %v", err)
+	}
+	t.Cleanup(func() { _ = tcpL.Close() })
+
+	ll, err := NewListener(context.Background(), tcpL, &tls.Config{
+		NextProtos:         []string{"broflake"},
+		InsecureSkipVerify: true,
+	})
+	if err != nil {
+		t.Fatalf("NewListener: %v", err)
+	}
+	t.Cleanup(func() { _ = ll.Close() })
+
+	out := buf.String()
+	if !strings.Contains(out, "Egress telemetry initialized") {
+		t.Fatalf("no startup line naming the build: %q", out)
+	}
+	if !strings.Contains(out, common.Version) {
+		t.Errorf("the startup line does not carry %s, so a deploy stays unverifiable: %q",
+			common.Version, out)
+	}
+}

egress/otellogs.go

@@ -69,7 +69,12 @@ func enableOTELLogs(ctx context.Context) func(context.Context) error {
 
 	exp, err := otlploghttp.New(ctx)
 	if err != nil {
-		slog.Warn("Log export disabled; could not build the OTLP log exporter", "err", err)
+		// The exporter reports what it could not parse, which for an endpoint
+		// problem is the endpoint — credentials included. Substituted rather
+		// than dropped, so the diagnostic survives without the secret.
+		slog.Warn("Log export disabled; could not build the OTLP log exporter",
+			"err", strings.ReplaceAll(err.Error(), endpoint, redactEndpoint(endpoint)),
+			"endpoint", redactEndpoint(endpoint), "from", endpointVar)
 		return func(context.Context) error { return nil }
 	}
 
@@ -189,14 +194,19 @@ func (h *teeHandler) WithGroup(name string) slog.Handler {
 
 // redactEndpoint strips anything an OTLP endpoint could legally carry as a
 // credential before it reaches a log. These URLs are configuration rather than
-// user input, but "https://user:token@collector/v1/logs" is a valid value and
-// this line is written to the journal and exported, so the raw form is the one
-// thing not worth printing. Scheme, host and path are what make the line useful.
+// user input, but "https://user:token@collector/v1/logs" and
+// "https://collector/v1/logs?api-key=..." are both valid values, and the journal
+// is read by more people than the config is. Scheme, host and path are what make
+// the line useful.
+//
+// Anything without a host is refused outright rather than returned. url.Parse
+// accepts opaque and hostless strings — "secret", "http:token" — without error,
+// and clearing User does nothing to those, so returning the parsed form would
+// echo the whole value. Same rule as sanitizeReportURL: with no structure to
+// rely on, there is no way to tell which part was secret.
 func redactEndpoint(raw string) string {
 	u, err := url.Parse(raw)
-	if err != nil {
-		// Do not echo a value that failed to parse: with no structure to rely
-		// on, there is no way to tell which part of it was secret.
+	if err != nil || u.Host == "" {
 		return "(unparseable)"
 	}
 	u.User = nil

egress/otellogs_test.go

@@ -400,3 +400,29 @@ func TestEnableOTELLogs_AnnouncesItselfAndRedactsTheEndpoint(t *testing.T) {
 		t.Error("no OTLP request reached the collector; export is announced but not wired")
 	}
 }
+
+// redactEndpoint's edge cases, which the enabled-path test cannot reach: it
+// supplies one realistic endpoint, so a mutation dropping the query/fragment
+// stripping — or returning a hostless value verbatim — would stay green there.
+func TestRedactEndpoint(t *testing.T) {
+	for _, tc := range []struct{ name, in, want string }{
+		{"plain endpoint survives", "https://collector:4318/v1/logs", "https://collector:4318/v1/logs"},
+		{"userinfo is dropped", "https://user:token@collector/v1/logs", "https://collector/v1/logs"},
+		{"query is dropped", "https://collector/v1/logs?api-key=SECRET", "https://collector/v1/logs"},
+		{"fragment is dropped", "https://collector/v1/logs#SECRET", "https://collector/v1/logs"},
+		{"bare query marker is dropped", "https://collector/v1/logs?", "https://collector/v1/logs"},
+		{"everything at once", "https://u:p@collector/v1/logs?k=S#f", "https://collector/v1/logs"},
+		// url.Parse accepts these without error, and clearing User does nothing
+		// to them — returning the parsed form would echo the secret whole.
+		{"opaque value is refused", "http:token", "(unparseable)"},
+		{"bare word is refused", "secret", "(unparseable)"},
+		{"hostless path is refused", "/v1/logs?api-key=SECRET", "(unparseable)"},
+		{"empty is refused", "", "(unparseable)"},
+	} {
+		t.Run(tc.name, func(t *testing.T) {
+			if got := redactEndpoint(tc.in); got != tc.want {
+				t.Errorf("redactEndpoint(%q) = %q, want %q", tc.in, got, tc.want)
+			}
+		})
+	}
+}

egress/refusals.go

@@ -166,32 +166,25 @@ func classifySubprotocolRefusal(raw, parsed []string) (reason refusalReason, msg
 	}
 }
 
-// peerAttrs returns slog attributes identifying who was refused.
-//
-// RemoteAddr alone is useless here: Caddy terminates TLS on :443 and proxies to
-// localhost:9001, so every RemoteAddr is 127.0.0.1 with an ephemeral port. The
-// real client is in X-Forwarded-For, which Caddy sets. Both are logged because
-// their disagreement is itself information — an X-Forwarded-For present with a
-// non-loopback RemoteAddr would mean something is reaching 9001 without going
-// through Caddy.
-//
-// User-Agent is the field that actually discriminates the hypotheses: one
-// repeated UA points at a misdirected health check or monitor, many distinct ones
-// point at real clients failing the handshake.
 // peerAttrs describes the peer behind a request without recording who it is.
 //
 // Country rather than address, deliberately. The egress necessarily sees the
-// donor's IP — it is the other end of the socket — but seeing it and writing it
-// into a log are different things: a log is retained, copied and queried, and
-// these are the addresses of people running circumvention software. The country
-// is what the diagnostics actually need, and it is already what the metrics
-// carry (attrDonorCountry), so the log and the counters now describe a peer the
-// same way.
+// donor's IP — it is the other end of the socket, and behind Caddy it arrives
+// as X-Forwarded-For — but seeing it and writing it into a log are different
+// things: a log is retained, copied and queried, and these are the addresses of
+// people running circumvention software. The country is what the diagnostics
+// actually need, and it is already what the metrics carry (attrDonorCountry),
+// so the log and the counters now describe a peer the same way.
+//
+// User-Agent is the field that discriminates the hypotheses these lines exist to
+// separate: one repeated UA points at a misdirected health check or monitor,
+// many distinct ones point at real clients failing the handshake. It identifies
+// a client build rather than a person, so it stays.
 //
-// What this gives up: an individual host is no longer identifiable from logs.
-// A refused population can still be characterised — country, user agent, and
-// the raw subprotocol values distinguish client builds — but pinpointing one
-// machine now has to be done live on the box rather than after the fact.
+// What this gives up: an individual host is no longer identifiable from logs. A
+// refused population can still be characterised — country, user agent and the
+// raw subprotocol values distinguish client builds — but pinpointing one machine
+// now has to happen live on the box rather than after the fact.
 func peerAttrs(r *http.Request) []any {
 	return []any{
 		"donor_country", donorCountry(donorGeoAddr(r, transportAddr(r))),