diff --git a/authbridge/authlib/listener/forwardproxy/server.go b/authbridge/authlib/listener/forwardproxy/server.go index 6883e0631..8a87ae84f 100644 --- a/authbridge/authlib/listener/forwardproxy/server.go +++ b/authbridge/authlib/listener/forwardproxy/server.go @@ -8,7 +8,9 @@ import ( "bytes" "context" cryptotls "crypto/tls" + "crypto/x509" "encoding/json" + "encoding/pem" "fmt" "io" "log/slog" @@ -20,6 +22,7 @@ import ( "sync/atomic" "time" + "errors" "github.com/rossoctl/cortex/authbridge/authlib/listener/httpx" "github.com/rossoctl/cortex/authbridge/authlib/listener/internal/bodyread" "github.com/rossoctl/cortex/authbridge/authlib/listener/internal/sseframe" @@ -103,6 +106,10 @@ type Server struct { tunnelsOpened atomic.Uint64 bridgeAttempts atomic.Uint64 bridgedRequests atomic.Uint64 + + // caNotBefore is parsed on first use and never changes for the process. + caNotBeforeOnce sync.Once + caNotBeforeStr string bridgeWarnOnce sync.Once bridgeWarned atomic.Bool } @@ -584,7 +591,28 @@ func (s *Server) serveOutbound(w http.ResponseWriter, r *http.Request, isBridge // r.URL.Host); host is the skip/log key. Returns true if it consumed the connection // (success OR an unrecoverable post-forge failure that was logged); false to fall // back to a plain tunnel — so no working call is ever broken. -func (s *Server) bridgeServe(client net.Conn, authority, host string) bool { +// tunnelRecorder records the tunnel-open event for one CONNECT, with the reason the +// bytes stayed opaque. Named rather than a bare func so the two callers' different +// contracts are visible in the type: handleConnect passes a real recorder, while the +// transparent listener passes noopRecorder because it already recorded eagerly before +// its own bridge decision. +type tunnelRecorder func(reason pipeline.TunnelReason) + +// noopRecorder is for a caller that has already recorded. Named so the call site says +// why it discards rather than looking like an oversight — and so the day the +// transparent listener is restructured, the remaining uses are greppable. +func noopRecorder(pipeline.TunnelReason) {} + +// bridgeServe attempts to terminate the client's TLS and serve the decrypted +// connection through the pipeline. Returns true when it handled the connection +// (bridged, or the client's connection died post-forge and there is nothing left +// to tunnel), false when it declined and the caller should tunnel instead. +// +// rec records the tunnel-open event with the reason the bytes stayed opaque. +// bridgeServe owns that call on every path it takes — including the successful +// one, where it must happen before ServeConn blocks — because two of the reasons +// are discovered only in here. +func (s *Server) bridgeServe(client net.Conn, authority, host string, rec tunnelRecorder) bool { // 1) Verify upstream reachability + cert via the dedicated client, BEFORE forging. // HEAD avoids GET side-effects; a non-2xx status still returns err==nil (cert // verified), which is all we need. Only a transport/TLS error fails here. The @@ -596,11 +624,13 @@ func (s *Server) bridgeServe(client net.Conn, authority, host string) bool { req, err := http.NewRequestWithContext(ctx, http.MethodHead, "https://"+authority, nil) if err != nil { slog.Info("tls-bridge passthrough", "host", host, "reason", "upstream-verify", "error", err) + rec(pipeline.TunnelOriginUnverified) return false } resp, err := s.TLSBridge.Upstream.Do(req) if err != nil { slog.Info("tls-bridge passthrough", "host", host, "reason", "upstream-verify", "error", err) + rec(pipeline.TunnelOriginUnverified) return false // fall back to plain tunnel — agent's own e2e TLS still reaches origin } _ = resp.Body.Close() @@ -609,14 +639,49 @@ func (s *Server) bridgeServe(client net.Conn, authority, host string) bool { tconn, err := s.TLSBridge.Term.Terminate(client, hostOnly(authority)) if err != nil { s.TLSBridge.Skip.Add(host) // pinned client → its retry will passthrough - slog.Warn("tls-bridge passthrough", "host", host, "reason", "handshake-fail", "error", err) - // Proof the client doesn't trust the CA. Warn now with the fix, because - // Skip.Add above means this host never reaches noteBridgeAttempt again. - if s.bridgedRequests.Load() == 0 { - s.noteBridgeHandshakeFailure() + reason := handshakeFailureReason(err) + // UNCONDITIONAL, and it names the client. Success elsewhere must not silence + // this: it used to sit behind bridgedRequests == 0, which treats CA trust as a + // property of the deployment. It is a property of each client, and on a + // machine running several agents they routinely disagree — one predates the + // CA, the rest do not — so the counter was non-zero and the message that + // explains the failure never printed. + // + // The client address is the discriminator, not the host: every client dials + // the same host, so the host cannot tell them apart. It has to be captured + // HERE, because the connection is gone by the time anyone reads the log and no + // later process listing can attribute it. + args := []any{ + "host", host, + "reason", reason, + "client", clientAddr(client), + "error", err, + } + // The restart advice goes ONLY on a real rejection. An EOF or a cipher + // mismatch would send someone restarting agents over something that was never + // about trust — and a minting failure on our own side is the worst case for + // that, since nothing they do to the client can fix it. + if reason == pipeline.TunnelClientRejectedCA { + // Short enough to read unwrapped. The lsof recipe for mapping the client + // port to a process lives in docs/laptop-service.md rather than being + // repeated on every occurrence of this line. + args = append(args, + "ca_not_before", s.caNotBefore(), + "fix", "restart clients started before ca_not_before") } + slog.Warn("tls-bridge passthrough", args...) + rec(reason) + // Deliberately NOT also calling noteBridgeHandshakeFailure. It fires + // warnBridgeUnused, whose fix is "point the client at the trust anchor" — so + // with bridgedRequests == 0 a single rejected forge produced two warnings with + // two different remedies, back to back. This one is strictly better informed: + // it knows which client and which CA. warnBridgeUnused still covers its own + // case, reached from the tunnel-threshold path. return true // conn is dead post-forge; nothing left to tunnel } + // Bridged: record with no reason, which is what tells abctl to fold this row into + // the decrypted inner request whose own action is the interesting one. + markBridged(rec) // 3) Serve the decrypted conn through the UNCHANGED pipeline. tlsbridge.ServeConn(tconn, http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { @@ -1107,9 +1172,13 @@ func (s *Server) handleConnect(w http.ResponseWriter, r *http.Request) { // (see handleRequest above). Shared with the transparent-redirect path. // Skipped when the destination matched SkipHosts: no plugin ran, so // there are no Invocations to attribute the event to. - if !skipped { - s.recordTunnelOpened(pctx) - } + // rec records the tunnel-open exactly once, on whichever path this CONNECT + // takes, carrying the reason the bytes stayed opaque. It is a closure rather + // than a call here because the reason is not known yet: recording before the + // bridge decision — as this did — made the two most useful reasons + // unrepresentable, since both are discovered inside bridgeServe. + rec := s.tunnelRecorderFor(pctx, skipped) + reason := pipeline.TunnelBridgeDisabled if s.TLSBridge != nil { pc := &peekedConn{Conn: clientConn, r: bufio.NewReaderSize(clientConn, sniffBufSize)} @@ -1117,11 +1186,17 @@ func (s *Server) handleConnect(w http.ResponseWriter, r *http.Request) { first, _ := pc.Peek(5) authority := r.Host // CONNECT target is already host:port key := hostOnly(r.Host) - if !s.TLSBridge.Skip.Contains(key) { - if v, _ := s.TLSBridge.Decision.Classify(key, portOf(r.Host), first); v == tlsbridge.Terminate { + if s.TLSBridge.Skip.Contains(key) { + // Distinct from client-rejected-ca: this client may trust the CA + // perfectly well and is being tunnelled because another one did not. + reason = pipeline.TunnelSkipCached + } else { + v, why := s.TLSBridge.Decision.Classify(key, portOf(r.Host), first) + reason = passthroughReason(why) + if v == tlsbridge.Terminate { s.noteBridgeAttempt() _ = upstream.Close() // bridgeServe dials its own verified upstream - if s.bridgeServe(clientConn, authority, key) { + if s.bridgeServe(clientConn, authority, key, rec) { return } // fell open → re-dial for the tunnel @@ -1134,6 +1209,10 @@ func (s *Server) handleConnect(w http.ResponseWriter, r *http.Request) { } } + // Every path that reaches here left the bytes opaque without entering + // bridgeServe, so this is where their reason gets recorded. + rec(reason) + // Bidirectional copy until either side closes. tunnel(clientConn, upstream) } @@ -1373,3 +1452,136 @@ func (s *Server) caFileHint() string { // Exists for tests: sync.Once has no public "has it run" query, and asserting // on log output would couple the test to the message text. func (s *Server) warnFired() bool { return s.bridgeWarned.Load() } + +// passthroughReason maps Decision.Classify's own reason string onto the stable +// wire vocabulary. Classify already distinguishes these cases; translating here +// rather than inventing a parallel set keeps one source of truth for WHY the +// bridge declined. +func passthroughReason(why string) pipeline.TunnelReason { + switch why { + case tlsbridge.ReasonPort: + return pipeline.TunnelPassthroughPort + case tlsbridge.ReasonNonTLS: + return pipeline.TunnelPassthroughNonTLS + case tlsbridge.ReasonSkip: + return pipeline.TunnelPassthroughHost + case "": + // Classify pairs "" with Terminate — it is NOT declining. The caller bridges + // and bridgeServe records that outcome, so there is no passthrough reason to + // give and "" is right here. + return "" + } + // Any OTHER value is a reason tlsbridge grew that this does not map. Never "": + // that is how a BRIDGED row is marked, so an unmapped passthrough would render as + // an em dash and read as "we decrypted this". Go cannot force an exhaustive + // switch, so the fallback is a value that shows up as itself and sends the reader + // here; TestPassthroughReasonCoversEveryClassifyReason fails when it happens. + return pipeline.TunnelPassthroughUnknown +} + +// markBridged records a successful bridge. Its whole job is to trip the once-guard +// with no reason attached, which is the signal abctl uses to fold the CONNECT row into +// the decrypted request. Named because `rec("")` at the call site reads like an +// oversight rather than a decision. +func markBridged(rec tunnelRecorder) { rec("") } + +// clientAddr names the client end of a connection for diagnostics, tolerating a +// nil conn or nil RemoteAddr so a logging path can never panic. +func clientAddr(c net.Conn) string { + if c == nil { + return "unknown" + } + a := c.RemoteAddr() + if a == nil { + return "unknown" + } + return a.String() +} + +// clientPort is the source port alone, for pasting into `lsof -nP -iTCP:`. +// Returns "" as a literal placeholder when it cannot be determined, so the +// suggested command still reads as a template rather than as something to run. +func clientPort(c net.Conn) string { + if _, port, err := net.SplitHostPort(clientAddr(c)); err == nil && port != "" { + return port + } + return "" +} + +// caNotBefore is the bridge CA's NotBefore, which is the line dividing clients +// that can trust it from clients that cannot: CA files are read once at process +// start, so anything older than this is holding a different CA (or none). +// Parsed once — the value is fixed for the process. +func (s *Server) caNotBefore() string { + s.caNotBeforeOnce.Do(func() { + s.caNotBeforeStr = "unknown" + if s.TLSBridge == nil || len(s.TLSBridge.CAPEM) == 0 { + return + } + blk, _ := pem.Decode(s.TLSBridge.CAPEM) + if blk == nil { + return + } + crt, err := x509.ParseCertificate(blk.Bytes) + if err != nil { + return + } + s.caNotBeforeStr = crt.NotBefore.Local().Format(time.RFC3339) + }) + return s.caNotBeforeStr +} + +// handshakeFailureReason narrows a failed forge to what we can actually claim. +// +// Terminator.Terminate returns exactly one error, from conn.Handshake(), and several +// very different things arrive through it: the client refusing our leaf, the client +// vanishing, a version/cipher/ALPN mismatch, and our own minter failing. Labelling +// them all "the client does not trust our CA" would send people restarting agents +// over problems that were never about trust. +// +// "remote error: tls:" is the discriminator — it means the PEER sent us an alert, so +// it actively rejected something rather than merely going away. bad_certificate and +// unknown_ca are the two alerts a client sends when it will not accept our chain. +// +// Matched on the string because the error is wrapped in the unexported +// *tls.permanentError: errors.As against tls.AlertError returns false for it, which I +// verified rather than assumed. +func handshakeFailureReason(err error) pipeline.TunnelReason { + if err == nil { + return "" + } + msg := err.Error() + switch { + case strings.Contains(msg, "remote error: tls: bad certificate"), + strings.Contains(msg, "remote error: tls: unknown certificate authority"): + return pipeline.TunnelClientRejectedCA + case errors.Is(err, io.EOF), strings.Contains(msg, "EOF"): + return pipeline.TunnelClientHungUp + } + return pipeline.TunnelHandshakeFailed +} + +// tunnelRecorderFor returns the recorder for one CONNECT: it records the tunnel-open +// at most once, with the reason the bytes stayed opaque. +// +// Extracted from handleConnect so the at-most-once invariant is reachable from a test. +// It was previously an inline closure, and the test that claimed to cover it did not: +// no current path calls the recorder twice, so removing the guard left every test +// passing. The guard defends against a future exit, which is exactly the kind of thing +// only a direct test can hold. +// +// sync.Once rather than a bool flag: with a flag the invariant holds only while every +// exit happens to re-read it, so a branch added later is silently uncovered. Once makes +// it unforgeable however the caller is rearranged. +// +// skipped means the destination matched SkipHosts, where no plugin ran and there is +// nothing to attribute an event to. +func (s *Server) tunnelRecorderFor(pctx *pipeline.Context, skipped bool) tunnelRecorder { + var once sync.Once + return func(reason pipeline.TunnelReason) { + if skipped { + return + } + once.Do(func() { s.recordTunnelOpened(pctx, reason) }) + } +} diff --git a/authbridge/authlib/listener/forwardproxy/skiphost_test.go b/authbridge/authlib/listener/forwardproxy/skiphost_test.go index 51b35ec64..1f48bd711 100644 --- a/authbridge/authlib/listener/forwardproxy/skiphost_test.go +++ b/authbridge/authlib/listener/forwardproxy/skiphost_test.go @@ -25,8 +25,10 @@ type markerPlugin struct { calls atomic.Int32 } -func (p *markerPlugin) Name() string { return "marker" } -func (p *markerPlugin) Capabilities() pipeline.PluginCapabilities { return pipeline.PluginCapabilities{} } +func (p *markerPlugin) Name() string { return "marker" } +func (p *markerPlugin) Capabilities() pipeline.PluginCapabilities { + return pipeline.PluginCapabilities{} +} func (p *markerPlugin) OnResponse(context.Context, *pipeline.Context) pipeline.Action { return pipeline.Action{Type: pipeline.Continue} } @@ -363,4 +365,3 @@ func TestForwardProxy_SkipHosts_CONNECT_BypassesPipeline(t *testing.T) { t.Errorf("skipped CONNECT: %d session(s) recorded, want 0", len(sessions)) } } - diff --git a/authbridge/authlib/listener/forwardproxy/transparent.go b/authbridge/authlib/listener/forwardproxy/transparent.go index 447a5478c..6ba2d1960 100644 --- a/authbridge/authlib/listener/forwardproxy/transparent.go +++ b/authbridge/authlib/listener/forwardproxy/transparent.go @@ -127,7 +127,13 @@ func (s *Server) HandleTransparentConn(clientConn net.Conn, dst string) { enableKeepalive(upstream) - s.recordTunnelOpened(pctx) + // The transparent path records before its own bridge decision for now, so it + // reports only that the tunnel opened. Threading the reason through here too + // means the same restructuring done for handleConnect; deliberately left for + // a follow-up rather than half-done, since this listener is off by default + // (--local skips it) and every reason it could report is already correct in + // the log. + s.recordTunnelOpened(pctx, "") if s.TLSBridge != nil { // host is the policy authority: ":port" when a name was @@ -141,7 +147,9 @@ func (s *Server) HandleTransparentConn(clientConn net.Conn, dst string) { v, reason := s.TLSBridge.Decision.Classify(key, portOf(dst), first) if v == tlsbridge.Terminate { _ = upstream.Close() // bridgeServe dials its own verified upstream; drop the pre-dial - if s.bridgeServe(clientConn, host, key) { + // No-op recorder: this path already recorded the tunnel-open eagerly + // above, so letting bridgeServe record again would double-count it. + if s.bridgeServe(clientConn, host, key, noopRecorder) { return } // bridgeServe fell open (upstream-verify failed) → re-dial for the tunnel. @@ -162,7 +170,7 @@ func (s *Server) HandleTransparentConn(clientConn net.Conn, dst string) { // HandleTransparentConn. MCP/Inference snapshots are nil by definition (the // bytes are opaque); Invocations from gate plugins and plugin-public Plugins // entries are still meaningful. -func (s *Server) recordTunnelOpened(pctx *pipeline.Context) { +func (s *Server) recordTunnelOpened(pctx *pipeline.Context, reason pipeline.TunnelReason) { if s.Sessions == nil { return } @@ -183,6 +191,10 @@ func (s *Server) recordTunnelOpened(pctx *pipeline.Context) { // Explicit opaque-tunnel marker so abctl can fold this CONNECT into // the decrypted inner request without inferring "tunnel" from shape. Tunnel: true, + // Why the bytes stayed opaque. The caller knows; this function does + // not, which is why it is a parameter rather than something derived + // here from host shape. + TunnelReason: reason, } // Always record the tunnel-open so passthrough/non-bridged tunnels (no // plugin activity) are still visible. For a TLS-bridged call abctl folds diff --git a/authbridge/authlib/listener/forwardproxy/transparent_test.go b/authbridge/authlib/listener/forwardproxy/transparent_test.go index 903bb9a19..de3d85ebb 100644 --- a/authbridge/authlib/listener/forwardproxy/transparent_test.go +++ b/authbridge/authlib/listener/forwardproxy/transparent_test.go @@ -20,7 +20,7 @@ func TestRecordTunnelOpened_SetsTunnelMarker(t *testing.T) { defer store.Close() s := &Server{Sessions: store} - s.recordTunnelOpened(&pipeline.Context{Direction: pipeline.Outbound, Host: "example.com:443"}) + s.recordTunnelOpened(&pipeline.Context{Direction: pipeline.Outbound, Host: "example.com:443"}, pipeline.TunnelSkipCached) v := store.View(session.DefaultSessionID) if v == nil || len(v.Events) != 1 { diff --git a/authbridge/authlib/listener/forwardproxy/tunnelreason_integration_test.go b/authbridge/authlib/listener/forwardproxy/tunnelreason_integration_test.go new file mode 100644 index 000000000..3ddbffc6f --- /dev/null +++ b/authbridge/authlib/listener/forwardproxy/tunnelreason_integration_test.go @@ -0,0 +1,434 @@ +package forwardproxy + +import ( + "bufio" + "bytes" + "crypto/tls" + "crypto/x509" + "encoding/pem" + "fmt" + "log/slog" + "net" + "net/http" + "net/http/httptest" + "strings" + "testing" + "time" + + "github.com/rossoctl/cortex/authbridge/authlib/pipeline" + "github.com/rossoctl/cortex/authbridge/authlib/plugins/plugintesting" + "github.com/rossoctl/cortex/authbridge/authlib/session" + "github.com/rossoctl/cortex/authbridge/authlib/tlsbridge" +) + +// bridgeForRejectTest builds a Server whose upstream verification SUCCEEDS (so +// bridgeServe reaches the forge step) against a throwaway TLS origin. +func bridgeForRejectTest(t *testing.T) (*Server, *session.Store, string) { + t.Helper() + + origin := httptest.NewTLSServer(http.HandlerFunc(func(w http.ResponseWriter, _ *http.Request) { + w.WriteHeader(http.StatusOK) + })) + t.Cleanup(origin.Close) + originCAPEM := pem.EncodeToMemory(&pem.Block{Type: "CERTIFICATE", Bytes: origin.Certificate().Raw}) + + src, err := tlsbridge.NewEphemeralSource() + if err != nil { + t.Fatalf("NewEphemeralSource: %v", err) + } + up, err := tlsbridge.NewUpstreamClient(originCAPEM) + if err != nil { + t.Fatalf("NewUpstreamClient: %v", err) + } + store := session.New(5*time.Minute, 100, 0) + t.Cleanup(store.Close) + + s := &Server{ + Sessions: store, + TLSBridge: &tlsbridge.Engine{ + Term: tlsbridge.NewTerminator(tlsbridge.NewMinter(src, tlsbridge.MinterOpts{})), + Skip: tlsbridge.NewSkipSet(), + Upstream: up, + CAPEM: src.CACertPEM(), + }, + } + return s, store, strings.TrimPrefix(origin.URL, "https://") +} + +// clientConnPair returns the PROXY-side conn of a TCP pair, having handed the client +// end to fn in a goroutine. Real TCP rather than net.Pipe because clientAddr / +// clientPort read RemoteAddr, and the port is the whole point of those. +func clientConnPair(t *testing.T, fn func(net.Conn)) net.Conn { + t.Helper() + ln, err := net.Listen("tcp", "127.0.0.1:0") + if err != nil { + t.Fatalf("listen: %v", err) + } + t.Cleanup(func() { _ = ln.Close() }) + + accepted := make(chan net.Conn, 1) + go func() { + c, aerr := ln.Accept() + if aerr != nil { + accepted <- nil + return + } + accepted <- c + }() + raw, err := net.Dial("tcp", ln.Addr().String()) + if err != nil { + t.Fatalf("dial: %v", err) + } + go fn(raw) + + srv := <-accepted + if srv == nil { + t.Fatal("accept failed") + } + t.Cleanup(func() { _ = srv.Close() }) + return srv +} + +// rejectingClient is a real TLS client that trusts nothing, so it refuses the forged +// leaf and sends a bad_certificate alert. That alert is what lets the proxy claim CA +// distrust rather than guess at it. +// +// The earlier version of this helper just wrote "nope" and closed, which produces +// "unexpected EOF" — a hang-up, not a rejection. It passed against a classifier that +// labelled every handshake error client-rejected-ca, and stopped passing the moment +// that claim was narrowed to what the evidence supports. The test was the +// counterexample to its own assertion. +func rejectingClient(t *testing.T) net.Conn { + t.Helper() + return clientConnPair(t, func(raw net.Conn) { + tc := tls.Client(raw, &tls.Config{ServerName: "example.com", RootCAs: x509.NewCertPool()}) + _ = tc.Handshake() // fails, and sends the alert on its way out + _ = tc.Close() + }) +} + +// hangUpClient sends bytes that are not a ClientHello and vanishes, which is what a +// cancelled request or a dead socket looks like. Distinct from a rejection, and it +// must NOT be told to restart anything. +func hangUpClient(t *testing.T) net.Conn { + t.Helper() + return clientConnPair(t, func(raw net.Conn) { + _, _ = raw.Write([]byte("nope")) + _ = raw.Close() + }) +} + +// TestClientRejectedCA_WarnsEvenAfterOtherTrafficBridged is the regression test +// for the bug this change exists to fix. +// +// The guidance ("does not trust the bridge CA") used to sit behind +// bridgedRequests == 0, which treats CA trust as a property of the deployment. +// It is a property of each client. On a machine running several agents they +// disagree — one predates the CA, the rest do not — so the counter was non-zero +// and the one message that explains the failure never printed. Diagnosing it +// then took the proxy log, the CA's NotBefore and a process listing. +func TestClientRejectedCA_WarnsEvenAfterOtherTrafficBridged(t *testing.T) { + s, store, authority := bridgeForRejectTest(t) + + // The condition that used to suppress everything: something has bridged. + s.bridgedRequests.Store(7) + + var logbuf bytes.Buffer + prev := slog.Default() + slog.SetDefault(slog.New(slog.NewTextHandler(&logbuf, &slog.HandlerOptions{Level: slog.LevelWarn}))) + t.Cleanup(func() { slog.SetDefault(prev) }) + + client := rejectingClient(t) + pctx := &pipeline.Context{Direction: pipeline.Outbound, Host: authority} + rec := func(reason pipeline.TunnelReason) { s.recordTunnelOpened(pctx, reason) } + + if handled := s.bridgeServe(client, authority, hostOnly(authority), rec); !handled { + t.Fatal("bridgeServe returned false; the connection is dead post-forge and must be reported handled") + } + + got := logbuf.String() + if !strings.Contains(got, string(pipeline.TunnelClientRejectedCA)) { + t.Errorf("warning did not name the reason %q despite bridgedRequests=7:\n%s", + pipeline.TunnelClientRejectedCA, got) + } + // The client address is the discriminator — the host cannot tell two clients + // apart because they all dial the same host. + if !strings.Contains(got, "client=") { + t.Errorf("warning did not name the client, so the offender is unattributable:\n%s", got) + } + if !strings.Contains(got, "ca_not_before=") { + t.Errorf("warning did not state the CA cutoff, which is what makes it actionable:\n%s", got) + } + // The lsof recipe deliberately does NOT appear here: review asked for a log line + // short enough to read unwrapped, so mapping a client port to a process lives in + // docs/laptop-service.md instead of being repeated on every occurrence. What the + // line must still carry is the client and the cutoff, asserted above. + if strings.Contains(got, "lsof") { + t.Errorf("the warning re-grew the lsof recipe; it belongs in the docs:\n%s", got) + } + + // And the timeline carries it, so this is visible without reading a log file. + v := store.View(session.DefaultSessionID) + if v == nil || len(v.Events) != 1 { + t.Fatalf("want exactly 1 tunnel event, got %+v", v) + } + if ev := v.Events[0]; !ev.Tunnel || ev.TunnelReason != pipeline.TunnelClientRejectedCA { + t.Errorf("event = {Tunnel:%v Reason:%q}, want {true %q}", + ev.Tunnel, ev.TunnelReason, pipeline.TunnelClientRejectedCA) + } +} + +// TestClientRejectedCA_SkipsHostAfterwards pins the existing self-healing +// behaviour: the failure is remembered so the client's retry tunnels instead of +// dying again. Unchanged by this work, asserted because the reason vocabulary +// now distinguishes that later tunnel (skip-cached) from this one. +func TestClientRejectedCA_SkipsHostAfterwards(t *testing.T) { + s, _, authority := bridgeForRejectTest(t) + host := hostOnly(authority) + if s.TLSBridge.Skip.Contains(host) { + t.Fatal("host skipped before any failure") + } + s.bridgeServe(rejectingClient(t), authority, host, noopRecorder) + if !s.TLSBridge.Skip.Contains(host) { + t.Error("host not skipped after a rejected forge; the client's retry would fail again") + } +} + +// TestClientHungUp_GetsNoRestartAdvice: an EOF mid-handshake is not proof of anything +// about trust, so it must not carry the restart-your-agents hint. Sending someone to +// restart agents over a cancelled request wastes their time and teaches them to +// distrust the message that matters. +func TestClientHungUp_GetsNoRestartAdvice(t *testing.T) { + s, store, authority := bridgeForRejectTest(t) + + var logbuf bytes.Buffer + prev := slog.Default() + slog.SetDefault(slog.New(slog.NewTextHandler(&logbuf, &slog.HandlerOptions{Level: slog.LevelWarn}))) + t.Cleanup(func() { slog.SetDefault(prev) }) + + pctx := &pipeline.Context{Direction: pipeline.Outbound, Host: authority} + s.bridgeServe(hangUpClient(t), authority, hostOnly(authority), + func(reason pipeline.TunnelReason) { s.recordTunnelOpened(pctx, reason) }) + + got := logbuf.String() + if !strings.Contains(got, string(pipeline.TunnelClientHungUp)) { + t.Errorf("want reason %q, got:\n%s", pipeline.TunnelClientHungUp, got) + } + if strings.Contains(got, "fix=") || strings.Contains(got, "ca_not_before") { + t.Errorf("a hang-up was given CA-trust advice it cannot justify:\n%s", got) + } + v := store.View(session.DefaultSessionID) + if v == nil || len(v.Events) != 1 || v.Events[0].TunnelReason != pipeline.TunnelClientHungUp { + t.Errorf("event reason = %+v, want %q", v, pipeline.TunnelClientHungUp) + } +} + +// connectThrough drives a real CONNECT through handleConnect against a throwaway +// origin and returns the tunnel-open event that was recorded, or nil. +// +// This exists because the tests above call bridgeServe directly, which leaves the +// recorder closure in handleConnect — recOnce, the skipped guard, and five of the nine +// reasons — with no coverage at all. Reading the control flow is not the same as +// pinning it. +func connectThrough(t *testing.T, s *Server, store *session.Store, target string, first []byte) *pipeline.SessionEvent { + t.Helper() + + srv := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { + s.handleRequest(w, r) + })) + t.Cleanup(srv.Close) + + raw, err := net.Dial("tcp", strings.TrimPrefix(srv.URL, "http://")) + if err != nil { + t.Fatalf("dial proxy: %v", err) + } + defer func() { _ = raw.Close() }() + + if _, err := fmt.Fprintf(raw, "CONNECT %s HTTP/1.1\r\nHost: %s\r\n\r\n", target, target); err != nil { + t.Fatalf("write CONNECT: %v", err) + } + br := bufio.NewReader(raw) + if _, err := http.ReadResponse(br, nil); err != nil { + t.Fatalf("read CONNECT response: %v", err) + } + if len(first) > 0 { + _, _ = raw.Write(first) + } + // The event is recorded on the CONNECT path before any copying; give it a moment. + deadline := time.Now().Add(2 * time.Second) + for time.Now().Before(deadline) { + if v := store.View(session.DefaultSessionID); v != nil && len(v.Events) > 0 { + return &v.Events[0] + } + time.Sleep(10 * time.Millisecond) + } + return nil +} + +// connectServer builds a Server wired the way handleConnect needs: an outbound +// pipeline holder (it runs the gate on the CONNECT itself) plus a session store. +func connectServer(t *testing.T, store *session.Store, bridge *tlsbridge.Engine) *Server { + t.Helper() + p, err := plugintesting.BuildPipeline(nil) + if err != nil { + t.Fatalf("BuildPipeline: %v", err) + } + return &Server{ + OutboundPipeline: pipeline.NewHolder(p), + Client: http.DefaultClient, + Sessions: store, + TLSBridge: bridge, + } +} + +// tlsRecordHead is the first five bytes of a TLS handshake record: content type 22, +// version 3.x, length. Enough for looksLikeTLSRecord, and enough to unblock the +// listener's Peek(5) — which waits for five bytes before it can classify anything, so +// a test that sends nothing after CONNECT hangs until its own deadline rather than +// exercising the branch it names. +var tlsRecordHead = []byte{0x16, 0x03, 0x01, 0x00, 0x00} + +// TestHandleConnect_RecordsReason covers the reasons only reachable through +// handleConnect's own wiring. Each is a different branch of the decision, and none was +// exercised end to end before. +func TestHandleConnect_RecordsReason(t *testing.T) { + origin := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, _ *http.Request) { + w.WriteHeader(http.StatusOK) + })) + defer origin.Close() + target := strings.TrimPrefix(origin.URL, "http://") + + t.Run("bridge-disabled", func(t *testing.T) { + store := session.New(5*time.Minute, 100, 0) + defer store.Close() + s := connectServer(t, store, nil) // no TLSBridge at all + ev := connectThrough(t, s, store, target, nil) + if ev == nil || ev.TunnelReason != pipeline.TunnelBridgeDisabled { + t.Fatalf("reason = %v, want %q", ev, pipeline.TunnelBridgeDisabled) + } + }) + + t.Run("skip-cached", func(t *testing.T) { + store := session.New(5*time.Minute, 100, 0) + defer store.Close() + d, err := tlsbridge.NewDecision(tlsbridge.DecisionOpts{Ports: map[int]bool{portOf(target): true}}) + if err != nil { + t.Fatal(err) + } + s := connectServer(t, store, &tlsbridge.Engine{Decision: d, Skip: tlsbridge.NewSkipSet()}) + s.TLSBridge.Skip.Add(hostOnly(target)) // a previous client's rejection + ev := connectThrough(t, s, store, target, tlsRecordHead) + if ev == nil || ev.TunnelReason != pipeline.TunnelSkipCached { + t.Fatalf("reason = %v, want %q", ev, pipeline.TunnelSkipCached) + } + }) + + t.Run("passthrough-port", func(t *testing.T) { + store := session.New(5*time.Minute, 100, 0) + defer store.Close() + // A port the bridge does not watch. + d, err := tlsbridge.NewDecision(tlsbridge.DecisionOpts{Ports: map[int]bool{1: true}}) + if err != nil { + t.Fatal(err) + } + s := connectServer(t, store, &tlsbridge.Engine{Decision: d, Skip: tlsbridge.NewSkipSet()}) + ev := connectThrough(t, s, store, target, tlsRecordHead) + if ev == nil || ev.TunnelReason != pipeline.TunnelPassthroughPort { + t.Fatalf("reason = %v, want %q", ev, pipeline.TunnelPassthroughPort) + } + }) + + t.Run("passthrough-nontls", func(t *testing.T) { + store := session.New(5*time.Minute, 100, 0) + defer store.Close() + d, err := tlsbridge.NewDecision(tlsbridge.DecisionOpts{Ports: map[int]bool{portOf(target): true}}) + if err != nil { + t.Fatal(err) + } + s := connectServer(t, store, &tlsbridge.Engine{Decision: d, Skip: tlsbridge.NewSkipSet()}) + // Plain HTTP bytes: watched port, but not a TLS record. + ev := connectThrough(t, s, store, target, []byte("GET / HTTP/1.1\r\n\r\n")) + if ev == nil || ev.TunnelReason != pipeline.TunnelPassthroughNonTLS { + t.Fatalf("reason = %v, want %q", ev, pipeline.TunnelPassthroughNonTLS) + } + }) +} + +// TestHandleConnect_RecordsExactlyOnce: the recorder is a closure with a recOnce +// guard, so a CONNECT must produce ONE tunnel-open however it is decided. A double +// record would double-count every tunnel in the timeline. +func TestHandleConnect_RecordsExactlyOnce(t *testing.T) { + origin := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, _ *http.Request) {})) + defer origin.Close() + target := strings.TrimPrefix(origin.URL, "http://") + + store := session.New(5*time.Minute, 100, 0) + defer store.Close() + s := connectServer(t, store, nil) + if ev := connectThrough(t, s, store, target, nil); ev == nil { + t.Fatal("no event recorded") + } + if v := store.View(session.DefaultSessionID); v == nil || len(v.Events) != 1 { + t.Errorf("want exactly 1 tunnel-open event, got %d", len(v.Events)) + } +} + +// TestHangUpAlsoSeedsTheSkip pins that a hang-up skips the host too, and that the +// second connection therefore reports skip-cached rather than client-rejected-ca. +// +// Raised in review as a possible defect — Skip is seeded before the failure is +// classified, so a hang-up caches the same state a confirmed rejection does. Keeping +// it deliberately: in EVERY failure class the forged handshake already killed that +// connection, so the client's retry needs a tunnel to work at all. Skipping only on +// client-rejected-ca would leave a client that closes without sending an alert — which +// is a real way to refuse a certificate — failing forever. +// +// What WAS wrong is what skip-cached claimed. It said "another client rejected the CA", +// which is true only sometimes; the seeding failure logs its own specific reason. This +// test exists so the behaviour is a choice on the record rather than an accident. +func TestHangUpAlsoSeedsTheSkip(t *testing.T) { + s, store, authority := bridgeForRejectTest(t) + host := hostOnly(authority) + pctx := &pipeline.Context{Direction: pipeline.Outbound, Host: authority} + + s.bridgeServe(hangUpClient(t), authority, host, + func(r pipeline.TunnelReason) { s.recordTunnelOpened(pctx, r) }) + + // The first failure reports what actually happened, not a CA rejection. + v := store.View(session.DefaultSessionID) + if v == nil || len(v.Events) != 1 { + t.Fatalf("want 1 event, got %+v", v) + } + if got := v.Events[0].TunnelReason; got != pipeline.TunnelClientHungUp { + t.Errorf("first failure reason = %q, want %q — a hang-up must not be reported as "+ + "a CA rejection", got, pipeline.TunnelClientHungUp) + } + // And it seeds the skip, so the client's retry can tunnel. + if !s.TLSBridge.Skip.Contains(host) { + t.Error("a hang-up did not seed the skip; the client's retry would forge again and " + + "die again") + } +} + +// TestPassthroughReasonNeverEmpty: the fallback must be the sentinel, never "". +// An empty reason is how a BRIDGED row is marked, so an unmapped passthrough would +// render as an em dash and read as "we decrypted this" — the opposite of the truth. +func TestPassthroughReasonNeverEmpty(t *testing.T) { + // Every reason Classify can DECLINE with must map to something non-empty. "" is + // excluded on purpose: Classify pairs it with Terminate, so it is not a + // passthrough at all and empty is the right answer there — asserted separately + // below rather than lumped in here, which is what made this test contradict the + // behaviour it was written to protect. + for _, why := range append([]string{"a-reason-nobody-mapped"}, tlsbridge.ClassifyReasons...) { + if got := passthroughReason(why); got == "" { + t.Errorf("passthroughReason(%q) = %q; an empty reason renders as BRIDGED", why, got) + } + } + if got := passthroughReason(""); got != "" { + t.Errorf(`passthroughReason("") = %q, want "" — Classify pairs "" with Terminate, `+ + "so the caller bridges and bridgeServe records the outcome", got) + } + if got := passthroughReason("a-reason-nobody-mapped"); got != pipeline.TunnelPassthroughUnknown { + t.Errorf("unmapped reason = %q, want the sentinel %q", got, pipeline.TunnelPassthroughUnknown) + } +} diff --git a/authbridge/authlib/listener/forwardproxy/tunnelreason_test.go b/authbridge/authlib/listener/forwardproxy/tunnelreason_test.go new file mode 100644 index 000000000..166478055 --- /dev/null +++ b/authbridge/authlib/listener/forwardproxy/tunnelreason_test.go @@ -0,0 +1,154 @@ +package forwardproxy + +import ( + "github.com/rossoctl/cortex/authbridge/authlib/session" + "net" + "strings" + "testing" + "time" + + "github.com/rossoctl/cortex/authbridge/authlib/pipeline" + "github.com/rossoctl/cortex/authbridge/authlib/tlsbridge" +) + +// TestPassthroughReason pins the mapping onto Classify's own vocabulary. If +// Classify gains a reason and this is not extended, the event silently carries +// "" — which reads as "bridged" and is the opposite of the truth. +func TestPassthroughReason(t *testing.T) { + for _, tc := range []struct { + why string + want pipeline.TunnelReason + }{ + {"port", pipeline.TunnelPassthroughPort}, + {"non-tls", pipeline.TunnelPassthroughNonTLS}, + {"skip", pipeline.TunnelPassthroughHost}, + {"", ""}, + } { + if got := passthroughReason(tc.why); got != tc.want { + t.Errorf("passthroughReason(%q) = %q, want %q", tc.why, got, tc.want) + } + } +} + +// TestPassthroughReasonCoversEveryClassifyReason is a real tripwire, not a restated +// list. It iterates tlsbridge.ClassifyReasons — the vocabulary Classify itself uses — +// so adding a reason there, or renaming one, fails HERE instead of silently producing +// an unmapped "" downstream. An unmapped reason renders as an em dash, which reads as +// "bridged": the opposite of what happened. +func TestPassthroughReasonCoversEveryClassifyReason(t *testing.T) { + if len(tlsbridge.ClassifyReasons) == 0 { + t.Fatal("tlsbridge.ClassifyReasons is empty; this test would assert nothing") + } + for _, why := range tlsbridge.ClassifyReasons { + got := passthroughReason(why) + if got == "" { + t.Errorf("Classify reason %q maps to \"\", which renders as a BRIDGED row", why) + continue + } + if len(got) > pluginCellWidth { + t.Errorf("reason %q is %d chars; it truncates in abctl's %d-wide PLUGIN cell, "+ + "so the timeline token stops matching the log token", got, len(got), pluginCellWidth) + } + } +} + +// pluginCellWidth mirrors abctl's PLUGIN column width. Duplicated deliberately: +// authlib must not import the TUI, and a reason that does not fit is a defect in the +// reason, not in the column. +const pluginCellWidth = 18 + +// TestClientAddrNeverPanics: these helpers exist only to build a log line, so a +// nil conn must degrade rather than take the proxy down on a diagnostic path. +func TestClientAddrNeverPanics(t *testing.T) { + if got := clientAddr(nil); got != "unknown" { + t.Errorf("clientAddr(nil) = %q, want %q", got, "unknown") + } + if got := clientPort(nil); got != "" { + t.Errorf("clientPort(nil) = %q, want a template placeholder, got %q", got, got) + } +} + +// TestClientPortIsTheDiscriminator is the point of the whole change: the host +// cannot tell two clients apart because they all dial the same host, so the +// source port is what identifies the offender. +func TestClientPortIsTheDiscriminator(t *testing.T) { + ln, err := net.Listen("tcp", "127.0.0.1:0") + if err != nil { + t.Fatalf("listen: %v", err) + } + defer func() { _ = ln.Close() }() + + c, err := net.Dial("tcp", ln.Addr().String()) + if err != nil { + t.Fatalf("dial: %v", err) + } + defer func() { _ = c.Close() }() + srv, err := ln.Accept() + if err != nil { + t.Fatalf("accept: %v", err) + } + defer func() { _ = srv.Close() }() + + // srv's RemoteAddr is the client end — the same thing bridgeServe holds. + addr := clientAddr(srv) + if !strings.HasPrefix(addr, "127.0.0.1:") { + t.Errorf("clientAddr = %q, want a loopback host:port", addr) + } + port := clientPort(srv) + if port == "" || !strings.HasSuffix(addr, ":"+port) { + t.Errorf("clientPort = %q, not the port of %q", port, addr) + } + // It must be the CLIENT's ephemeral port, not the listener's: the listener + // port is shared by every client and would identify nothing. + if _, lport, _ := net.SplitHostPort(ln.Addr().String()); port == lport { + t.Errorf("clientPort returned the listener port %q — that cannot discriminate between clients", port) + } +} + +// TestCANotBeforeWithoutBridge: the value appears in a log line on a failure +// path, so its absence must read as "unknown" rather than crash or print junk. +func TestCANotBeforeWithoutBridge(t *testing.T) { + s := &Server{} + if got := s.caNotBefore(); got != "unknown" { + t.Errorf("caNotBefore with no bridge = %q, want %q", got, "unknown") + } +} + +// TestTunnelRecorderRecordsAtMostOnce exercises the invariant directly. +// +// The integration test that claimed to cover this did not: no current path calls the +// recorder twice, so bypassing the guard left every test green. Verified by doing +// exactly that. The guard exists for a future exit, so only a direct call can hold it. +func TestTunnelRecorderRecordsAtMostOnce(t *testing.T) { + store := session.New(5*time.Minute, 100, 0) + defer store.Close() + s := &Server{Sessions: store} + pctx := &pipeline.Context{Direction: pipeline.Outbound, Host: "example.com:443"} + + rec := s.tunnelRecorderFor(pctx, false) + rec(pipeline.TunnelSkipCached) + rec(pipeline.TunnelClientRejectedCA) // a second exit firing must be swallowed + rec("") + + v := store.View(session.DefaultSessionID) + if v == nil || len(v.Events) != 1 { + t.Fatalf("want exactly 1 event after 3 calls, got %d", len(v.Events)) + } + if got := v.Events[0].TunnelReason; got != pipeline.TunnelSkipCached { + t.Errorf("recorded reason = %q, want the FIRST call's %q", got, pipeline.TunnelSkipCached) + } +} + +// TestTunnelRecorderSkipsSkipHosts: a SkipHosts destination ran no plugins, so there is +// nothing to attribute an event to and none must be written. +func TestTunnelRecorderSkipsSkipHosts(t *testing.T) { + store := session.New(5*time.Minute, 100, 0) + defer store.Close() + s := &Server{Sessions: store} + rec := s.tunnelRecorderFor(&pipeline.Context{Direction: pipeline.Outbound, Host: "h:443"}, true) + rec(pipeline.TunnelPassthroughHost) + + if v := store.View(session.DefaultSessionID); v != nil && len(v.Events) != 0 { + t.Errorf("a SkipHosts tunnel recorded %d event(s); want none", len(v.Events)) + } +} diff --git a/authbridge/authlib/pipeline/session.go b/authbridge/authlib/pipeline/session.go index 1ec1a94f5..d923d8448 100644 --- a/authbridge/authlib/pipeline/session.go +++ b/authbridge/authlib/pipeline/session.go @@ -149,8 +149,83 @@ type SessionEvent struct { // signal rather than inferring "tunnel" from host/extension shape, which // an ordinary unparsed request could otherwise mimic. Tunnel bool + + // TunnelReason says WHY the bytes were left opaque. Empty when Tunnel is + // false, and empty on a bridged CONNECT (abctl folds that row into the + // decrypted inner request, whose own action is the interesting one). + // + // It exists because "tunnel" with no reason is indistinguishable from a + // routine egress passthrough, and the two demand opposite responses: a + // configured passthrough is working as intended, while a client that + // rejected the bridge certificate means every plugin is blind to that + // traffic and someone has to restart something. Diagnosing the latter + // previously required the proxy log, the CA's NotBefore and a process + // listing — none of which the timeline hinted at. + TunnelReason TunnelReason } +// TunnelReason is why an opaque tunnel stayed opaque. +// +// A named type rather than a bare string so the compiler catches a typo on the +// producer side and on every consumer: these values are decoded from the wire, +// enumerated in the operator docs and pinned by tests, and a misspelling in any of +// those places would otherwise be a value that renders as itself and means nothing. +// It marshals as a plain JSON string, so the wire contract is unchanged. +type TunnelReason string + +// Tunnel reasons. Stable strings: abctl renders them and operators grep them. +// +// Each is at most 18 characters, which is the width of abctl's PLUGIN column +// (events_columns.go). A longer value truncates in the cell, which would break the +// one property that makes these useful — that the token in the timeline is the same +// token you grep for in the proxy log. +const ( + // TunnelClientRejectedCA — the client sent a TLS alert rejecting our leaf, so it + // does not trust the bridge CA. Claimed ONLY on a "remote error: tls: + // bad certificate" / "unknown certificate authority", which is the peer actively + // refusing us. Usually a process that started before the CA was minted, since CA + // files are read once at startup. + TunnelClientRejectedCA TunnelReason = "client-rejected-ca" + // TunnelClientHungUp — the client disappeared mid-handshake without sending an + // alert. CA distrust is one cause, but so is a cancelled request or a dead + // socket, so this deliberately does NOT tell anyone to restart anything. + TunnelClientHungUp TunnelReason = "client-hung-up" + // TunnelHandshakeFailed — the handshake failed for some other reason: a version, + // cipher or ALPN mismatch, or our own certificate minting failing. Not the + // client's fault as far as we can tell, so it gets no client-side advice. The + // logged error= field carries the specific cause. + TunnelHandshakeFailed TunnelReason = "handshake-failed" + // TunnelOriginUnverified — WE could not verify the origin, so bridging would have + // meant vouching for a certificate we could not check. + TunnelOriginUnverified TunnelReason = "origin-unverified" + // TunnelSkipCached — an earlier handshake FAILURE for this host is still inside the + // skip window, so no interception was attempted at all. + // + // Deliberately does not say why that earlier attempt failed. The skip is seeded by + // any failed forge — a rejection, a hang-up, a cipher mismatch — because in every + // one of those the connection died mid-handshake and the client's retry needs a + // tunnel to work at all. Claiming "another client rejected the CA" here would be + // right only some of the time. The seeding failure logged its own specific reason + // when it happened; that is where the why lives. + // + // Distinct from client-rejected-ca either way: THIS client may well trust the CA + // and is being tunnelled because an earlier one had trouble. + TunnelSkipCached TunnelReason = "skip-cached" + // TunnelBridgeDisabled — no TLS bridge is configured. + TunnelBridgeDisabled TunnelReason = "bridge-disabled" + // TunnelPassthroughPort, TunnelPassthroughNonTLS and TunnelPassthroughHost mirror + // Decision.Classify's own reasons for declining to intercept. All three are + // working as intended. + TunnelPassthroughPort TunnelReason = "passthrough-port" + TunnelPassthroughNonTLS TunnelReason = "passthrough-nontls" + TunnelPassthroughHost TunnelReason = "passthrough-host" + // TunnelPassthroughUnknown is the fallback when a lower layer declines to + // intercept for a reason this vocabulary does not yet name. It exists so that + // case can never produce the EMPTY string, which a consumer reads as "bridged" — + // the exact opposite of what happened, and invisible in a timeline. + TunnelPassthroughUnknown TunnelReason = "passthrough-unknown" +) + // EventTLS describes the TLS state of a connection that produced a // session event. Populated by the reverse-proxy listener when mTLS is // enabled and the inbound connection completed a TLS handshake; @@ -229,27 +304,32 @@ type sessionEventWire struct { DurationMs int64 `json:"durationMs,omitempty"` TLS *EventTLS `json:"tls,omitempty"` Tunnel bool `json:"tunnel,omitempty"` + // omitempty so both skew directions are safe: an old abctl ignores an unknown + // key, and a new abctl against an old proxy sees "" and renders exactly what it + // renders today. + TunnelReason TunnelReason `json:"tunnelReason,omitempty"` } func (e SessionEvent) MarshalJSON() ([]byte, error) { return json.Marshal(sessionEventWire{ - SessionID: e.SessionID, - At: e.At, - Direction: e.Direction, - Phase: e.Phase, - RequestID: e.RequestID, - A2A: e.A2A, - MCP: e.MCP, - Inference: e.Inference, - Invocations: e.Invocations, - Plugins: e.Plugins, - Identity: e.Identity, - StatusCode: e.StatusCode, - Error: e.Error, - Host: e.Host, - DurationMs: e.Duration.Milliseconds(), - TLS: e.TLS, - Tunnel: e.Tunnel, + SessionID: e.SessionID, + At: e.At, + Direction: e.Direction, + Phase: e.Phase, + RequestID: e.RequestID, + A2A: e.A2A, + MCP: e.MCP, + Inference: e.Inference, + Invocations: e.Invocations, + Plugins: e.Plugins, + Identity: e.Identity, + StatusCode: e.StatusCode, + Error: e.Error, + Host: e.Host, + DurationMs: e.Duration.Milliseconds(), + TLS: e.TLS, + Tunnel: e.Tunnel, + TunnelReason: e.TunnelReason, }) } @@ -262,23 +342,24 @@ func (e *SessionEvent) UnmarshalJSON(data []byte) error { return err } *e = SessionEvent{ - SessionID: w.SessionID, - At: w.At, - Direction: w.Direction, - Phase: w.Phase, - RequestID: w.RequestID, - A2A: w.A2A, - MCP: w.MCP, - Inference: w.Inference, - Invocations: w.Invocations, - Plugins: w.Plugins, - Identity: w.Identity, - StatusCode: w.StatusCode, - Error: w.Error, - Host: w.Host, - Duration: time.Duration(w.DurationMs) * time.Millisecond, - TLS: w.TLS, - Tunnel: w.Tunnel, + SessionID: w.SessionID, + At: w.At, + Direction: w.Direction, + Phase: w.Phase, + RequestID: w.RequestID, + A2A: w.A2A, + MCP: w.MCP, + Inference: w.Inference, + Invocations: w.Invocations, + Plugins: w.Plugins, + Identity: w.Identity, + StatusCode: w.StatusCode, + Error: w.Error, + Host: w.Host, + Duration: time.Duration(w.DurationMs) * time.Millisecond, + TLS: w.TLS, + Tunnel: w.Tunnel, + TunnelReason: w.TunnelReason, } return nil } diff --git a/authbridge/authlib/pipeline/session_test.go b/authbridge/authlib/pipeline/session_test.go index 8097e7463..21e201ac1 100644 --- a/authbridge/authlib/pipeline/session_test.go +++ b/authbridge/authlib/pipeline/session_test.go @@ -2,6 +2,8 @@ package pipeline import ( "encoding/json" + "os" + "reflect" "strings" "testing" "time" @@ -233,3 +235,93 @@ func TestSessionEvent_PluginsMap_JSONRoundTrip(t *testing.T) { t.Errorf("rate-limiter payload drifted: %q", got) } } + +// TestSessionEventWire_HasEveryDomainField is the tripwire the round-trip test +// cannot be. +// +// SessionEvent has no struct tags: it marshals through the hand-maintained +// sessionEventWire DTO with field-by-field copies. Add a field to SessionEvent and +// forget the DTO and the field never crosses the wire — which is exactly what +// happened to TunnelReason. Every existing test stayed green, because +// TestSessionEvent_JSONRoundTrip compares Marshal→Unmarshal→Marshal for byte +// identity and a field absent from the DTO on BOTH sides round-trips identically. +// Symmetric loss is invisible to a symmetric test. +// +// This asserts structurally instead: for every exported field on SessionEvent there +// must be one of the same name on sessionEventWire. It cannot be satisfied by +// accident, and it fails at the moment the two drift rather than in the field. +func TestSessionEventWire_HasEveryDomainField(t *testing.T) { + domain := reflect.TypeOf(SessionEvent{}) + wire := reflect.TypeOf(sessionEventWire{}) + + // Deliberate renames, kept explicit so the check stays strict. Duration is + // milliseconds on the wire, and the DTO field is named for the unit rather than + // silently changing what a same-named field means. + renamed := map[string]string{"Duration": "DurationMs"} + + for i := 0; i < domain.NumField(); i++ { + f := domain.Field(i) + if !f.IsExported() { + continue + } + want := f.Name + if alias, ok := renamed[want]; ok { + want = alias + } + if _, ok := wire.FieldByName(want); !ok { + t.Errorf("SessionEvent.%s has no sessionEventWire counterpart (looked for %q): "+ + "it will never reach the wire, and the round-trip test cannot see that", + f.Name, want) + } + } +} + +// TestSessionEventWire_EveryFieldSerializes is the value-level half: a populated +// event must produce a JSON key per wire field. Catches a field present in the DTO +// but missing from MarshalJSON's literal — the other way the two halves can drift. +func TestSessionEventWire_EveryFieldSerializes(t *testing.T) { + ev := SessionEvent{ + SessionID: "s", At: time.Now(), Direction: Outbound, Phase: SessionRequest, + RequestID: "r", Host: "h:443", StatusCode: 200, Duration: time.Second, + Tunnel: true, TunnelReason: TunnelClientRejectedCA, + } + b, err := json.Marshal(ev) + if err != nil { + t.Fatalf("Marshal: %v", err) + } + var got map[string]json.RawMessage + if err := json.Unmarshal(b, &got); err != nil { + t.Fatalf("Unmarshal to map: %v", err) + } + for _, key := range []string{ + "sessionId", "at", "direction", "phase", "requestId", + "host", "statusCode", "durationMs", "tunnel", "tunnelReason", + } { + if _, ok := got[key]; !ok { + t.Errorf("populated event produced no %q key; got %s", key, b) + } + } +} + +// TestTunnelReasonsAreDocumented pins every reason against the operator docs. +// +// The doc previously said "two other reasons" when there were four, and omitted +// origin-unverified — the one that points at the destination rather than the client, +// and so the one most likely to send someone looking in the wrong place. A reason +// nobody can look up is barely better than the em dash it replaced. +func TestTunnelReasonsAreDocumented(t *testing.T) { + doc, err := os.ReadFile("../../docs/laptop-service.md") + if err != nil { + t.Skipf("docs not readable from here: %v", err) + } + for _, reason := range []TunnelReason{ + TunnelClientRejectedCA, TunnelClientHungUp, TunnelHandshakeFailed, + TunnelOriginUnverified, TunnelSkipCached, TunnelBridgeDisabled, + TunnelPassthroughPort, TunnelPassthroughNonTLS, TunnelPassthroughHost, + } { + if !strings.Contains(string(doc), string(reason)) { + t.Errorf("tunnel reason %q is not in laptop-service.md; an operator who sees "+ + "it in the timeline has nowhere to look it up", reason) + } + } +} diff --git a/authbridge/authlib/tlsbridge/decision.go b/authbridge/authlib/tlsbridge/decision.go index 4a10a2bd4..b67c1de7b 100644 --- a/authbridge/authlib/tlsbridge/decision.go +++ b/authbridge/authlib/tlsbridge/decision.go @@ -145,18 +145,33 @@ func (d *Decision) HandlesPort(port int) bool { return d.ports[port] } // bridge intercepts everything eligible on the configured ports (no in-cluster // vs external distinction): a port + valid-TLS-record + not-skip-listed // connection is terminated; anything else passes through. +// Reasons Classify gives for declining to intercept. Exported and enumerated in +// ClassifyReasons so a consumer that maps them can assert it covers every one — +// otherwise adding a reason here silently produces an unmapped value downstream, and +// an unmapped tunnel reason renders as "bridged", the opposite of the truth. +const ( + ReasonPort = "port" + ReasonNonTLS = "non-tls" + ReasonSkip = "skip" +) + +// ClassifyReasons is every non-empty reason Classify can return. Keep in step with +// the switch below; the mapping tests in dependent packages derive their coverage +// from this slice rather than restating it. +var ClassifyReasons = []string{ReasonPort, ReasonNonTLS, ReasonSkip} + func (d *Decision) Classify(host string, port int, first []byte) (Verdict, string) { if !d.ports[port] { - return Passthrough, "port" + return Passthrough, ReasonPort } if !looksLikeTLSRecord(first) { - return Passthrough, "non-tls" + return Passthrough, ReasonNonTLS } // Glob, not exact match: the tooling hosts this skips come in families // (api./codeload./uploads.github.com), and Match strips the port so a caller // may pass either host or host:port. if d.skip.Match(host) { - return Passthrough, "skip" + return Passthrough, ReasonSkip } return Terminate, "" } diff --git a/authbridge/cmd/abctl/tui/events_pane.go b/authbridge/cmd/abctl/tui/events_pane.go index 9d2fb0bef..69ee0bf8d 100644 --- a/authbridge/cmd/abctl/tui/events_pane.go +++ b/authbridge/cmd/abctl/tui/events_pane.go @@ -370,11 +370,30 @@ const tunnelAction = "tunnel" func rowAction(er eventRow, invs []pipeline.Invocation) (action, plugin string) { action, plugin = eventAction(invs) if er.event != nil && er.event.Tunnel && action == "—" { - return tunnelAction, "—" + // The PLUGIN cell carries the REASON on these rows. No plugin ran — that + // is what makes the row a tunnel — so the cell would otherwise be a + // second em dash beside the first, on the one row type that needs an + // explanation most. "tunnel" alone cannot distinguish a passthrough + // working as designed from a client that rejected the bridge CA, and + // those demand opposite responses. + return tunnelAction, tunnelReasonCell(er.event.TunnelReason) } return action, plugin } +// tunnelReasonCell renders SessionEvent.TunnelReason for the PLUGIN column. +// +// Reasons are already short, kebab-case and stable, so they are shown verbatim +// rather than prettified: an operator grepping the proxy log for the same string +// should find the same token. An unknown reason is passed through untouched — a +// newer proxy paired with an older abctl should show the new reason, not hide it. +func tunnelReasonCell(reason pipeline.TunnelReason) string { + if reason == "" { + return "—" + } + return string(reason) +} + // eventAction folds a message's per-plugin invocations into the single ACTION + // PLUGIN cell pair shown in the timeline. The headline reflects what actually // took effect: diff --git a/authbridge/cmd/abctl/tui/events_pane_test.go b/authbridge/cmd/abctl/tui/events_pane_test.go index f3fb8dfc7..935f4daba 100644 --- a/authbridge/cmd/abctl/tui/events_pane_test.go +++ b/authbridge/cmd/abctl/tui/events_pane_test.go @@ -960,3 +960,45 @@ func TestBuildEventRows_TunnelRowsAreLabelled(t *testing.T) { t.Errorf("bridged row ACTION = %q, want observe", a) } } + +// TestTunnelReasonCell: the PLUGIN cell carries the reason on a tunnel row, +// because no plugin ran there and a second em dash beside the first is what made +// a routine passthrough and a blind-to-everything CA rejection look identical. +func TestTunnelReasonCell(t *testing.T) { + for _, tc := range []struct { + reason pipeline.TunnelReason + want string + }{ + {"", "—"}, // bridged: folded into the inner request + {pipeline.TunnelClientRejectedCA, string(pipeline.TunnelClientRejectedCA)}, + {pipeline.TunnelSkipCached, string(pipeline.TunnelSkipCached)}, + {"some-future-reason", "some-future-reason"}, // newer proxy, older abctl + } { + if got := tunnelReasonCell(tc.reason); got != tc.want { + t.Errorf("tunnelReasonCell(%q) = %q, want %q", tc.reason, got, tc.want) + } + } +} + +// TestRowActionSurfacesTunnelReason: the reason has to reach the row, not just +// the event. A tunnel row shows "tunnel" plus WHY; a row where a plugin acted +// keeps that plugin's headline, because a gate CAN deny a CONNECT and that deny +// must not be replaced by a tunnel label. +func TestRowActionSurfacesTunnelReason(t *testing.T) { + ev := &pipeline.SessionEvent{Tunnel: true, TunnelReason: pipeline.TunnelClientRejectedCA} + action, plugin := rowAction(eventRow{event: ev}, nil) + if action != tunnelAction { + t.Errorf("action = %q, want %q", action, tunnelAction) + } + if plugin != string(pipeline.TunnelClientRejectedCA) { + t.Errorf("plugin cell = %q, want the reason %q", plugin, pipeline.TunnelClientRejectedCA) + } + + // A denied CONNECT keeps its own headline. + denied := &pipeline.SessionEvent{Tunnel: true, TunnelReason: pipeline.TunnelSkipCached} + invs := []pipeline.Invocation{{Plugin: "ibac", Action: "deny"}} + action, _ = rowAction(eventRow{event: denied}, invs) + if action == tunnelAction { + t.Error("a denied CONNECT was relabelled 'tunnel'; the deny must headline") + } +} diff --git a/authbridge/docs/laptop-service.md b/authbridge/docs/laptop-service.md index 814879755..eef74a969 100644 --- a/authbridge/docs/laptop-service.md +++ b/authbridge/docs/laptop-service.md @@ -166,6 +166,55 @@ followed by this machine's public roots. Pointing a replacing variable at `ca.cr would leave that tool trusting one private CA and nothing else, which breaks every direct TLS call it makes. +### Everything shows as `tunnel` and no plugin ever runs + +`abctl observe` shows rows like this, with `tunnel` in ACTION and no method or status: + +``` +18:00:02 out req tunnel client-rejected-ca ete-litellm.example.com +``` + +The reason is in the PLUGIN column. `client-rejected-ca` means that client refused +the bridge certificate, so nothing downstream can read the traffic. The usual cause +is a process that **started before the CA existed**: CA files are read once at +startup, so an agent already running when Cortex was first installed — or when +`~/.cortex` was deleted and recreated — is holding a different CA, or none. + +The proxy log names the offender and the cutoff: + +```sh +grep 'client-rejected-ca' ~/.cortex/proxy.log +# ... client=127.0.0.1:58041 ca_not_before=2026-09-09T17:11:39-04:00 +# fix=restart clients that started before ca_not_before ... +``` + +Map that client port to a process, then restart it: + +```sh +lsof -nP -iTCP:58041 # -> COMMAND / PID +ps -o lstart= -p # started before ca_not_before? restart it +``` + +The port has to come from the log rather than a later `lsof` sweep: the connection +is gone by the time you look, so nothing after the fact can attribute it. + +The other reasons you may see, and what each one asks of you: + +| Reason | Meaning | Act? | +| --- | --- | --- | +| `passthrough-host` | A host Cortex deliberately does not intercept (GitHub, module proxies, package registries). | no | +| `passthrough-port` | Not a port the bridge watches. | no | +| `passthrough-nontls` | The bytes were not a TLS handshake, so there was nothing to terminate. | no | +| `skip-cached` | An earlier handshake for this host failed, so it is not intercepted for **anyone** for a few minutes. Any failed handshake seeds this, not only a CA rejection — the seeding failure logged its own reason. | look for the earlier failure in `proxy.log` | +| `bridge-disabled` | No TLS bridge is configured. | only if you wanted one | +| `client-hung-up` | The client vanished mid-handshake. Often a cancelled request; not evidence about trust, which is why it carries no advice. | usually no | +| `handshake-failed` | Some other handshake failure — a version, cipher or ALPN mismatch, or Cortex failing to mint a certificate. | check `error=` in the log | +| `origin-unverified` | **Cortex** could not verify the destination's certificate, so it declined to vouch for it. Bridging would have meant terminating TLS for a server we could not authenticate. | investigate the destination | + +Only `client-rejected-ca` asks you to restart anything. The others are either working as +intended or point somewhere other than your agents — which is why the reason is worth +reading before acting on it. + ### Developer tooling is not intercepted at all `gh`, `go`, `pip` and `npm` work out of the box, without trusting anything. The