Skip to content

Commit f8ecb32

Browse files
authored
Merge pull request #527 from huang195/feat/abctl-one-row-per-message
Feat(abctl): one row per network message, show every message
2 parents c52044e + 58ff6d8 commit f8ecb32

23 files changed

Lines changed: 1604 additions & 1006 deletions

File tree

authbridge/authlib/config/config.go

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -198,7 +198,7 @@ type SessionConfig struct {
198198
// "user didn't say" with "user said false" and silently flip the default.
199199
Enabled *bool `yaml:"enabled" json:"enabled"`
200200
TTL string `yaml:"ttl" json:"ttl"` // duration string; default: 30m
201-
MaxEvents int `yaml:"max_events" json:"max_events"` // max events per session; default: 100
201+
MaxEvents int `yaml:"max_events" json:"max_events"` // max events per session; default: 500
202202
MaxSessions int `yaml:"max_sessions" json:"max_sessions"` // max concurrent sessions; default: 100 (0 = unlimited)
203203
}
204204

Lines changed: 106 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,106 @@
1+
package forwardproxy
2+
3+
import (
4+
"bytes"
5+
"io"
6+
"net/http"
7+
"net/http/httptest"
8+
"testing"
9+
"time"
10+
11+
"github.com/kagenti/kagenti-extensions/authbridge/authlib/pipeline"
12+
"github.com/kagenti/kagenti-extensions/authbridge/authlib/plugins/inferenceparser"
13+
"github.com/kagenti/kagenti-extensions/authbridge/authlib/plugins/mcpparser"
14+
"github.com/kagenti/kagenti-extensions/authbridge/authlib/session"
15+
)
16+
17+
// TestForwardProxy_MCP_SSEResponse_RecordsObserve reproduces the live
18+
// weather-tool-mcp scenario: an MCP tools/list call whose response is
19+
// text/event-stream (Streamable HTTP). The request is parsed (observe), and
20+
// the RESPONSE must also be parsed into a result + recorded as an mcp-parser
21+
// observe on the response event. The live cluster showed result=N,
22+
// invocations=[] on the response — this test pins whether the proxy+parser
23+
// path reproduces that.
24+
func TestForwardProxy_MCP_SSEResponse_RecordsObserve(t *testing.T) {
25+
// Upstream mimics weather-tool-mcp: tools/list -> SSE with one data frame
26+
// carrying the JSON-RPC result, exactly as FastMCP emits it.
27+
upstream := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, _ *http.Request) {
28+
w.Header().Set("Content-Type", "text/event-stream")
29+
w.WriteHeader(http.StatusOK)
30+
io.WriteString(w, "event: message\ndata: {\"jsonrpc\":\"2.0\",\"id\":2,\"result\":{\"tools\":[{\"name\":\"get_weather\"}]}}\n\n")
31+
if f, ok := w.(http.Flusher); ok {
32+
f.Flush()
33+
}
34+
}))
35+
defer upstream.Close()
36+
37+
store := session.New(5*time.Minute, 100, 0)
38+
defer store.Close()
39+
40+
// Production builds Configurable plugins through plugins.Build, which
41+
// wraps them via pipeline.WrapConfigured. mcp-parser is Configurable +
42+
// StreamingResponder, so it MUST stay a StreamingResponder after wrapping
43+
// — that's the bug this test guards (a bare wrapper drops OnResponseFrame
44+
// and RunResponseFrame skips it, leaving the SSE response unparsed).
45+
// inference-parser is not Configurable, so it's added raw, as in production.
46+
pipe, err := pipeline.New([]pipeline.Plugin{
47+
pipeline.WrapConfigured(mcpparser.NewMCPParser(), nil),
48+
inferenceparser.NewInferenceParser(),
49+
})
50+
if err != nil {
51+
t.Fatal(err)
52+
}
53+
srv, err := NewServer(pipeline.NewHolder(pipe), store, nil)
54+
if err != nil {
55+
t.Fatalf("NewServer: %v", err)
56+
}
57+
proxy := httptest.NewServer(srv.Handler())
58+
defer proxy.Close()
59+
60+
reqBody := `{"jsonrpc":"2.0","id":2,"method":"tools/list"}`
61+
req, _ := http.NewRequest("POST", upstream.URL+"/mcp", bytes.NewReader([]byte(reqBody)))
62+
req.Header.Set("Content-Type", "application/json")
63+
proxyClient := &http.Client{Transport: &http.Transport{Proxy: http.ProxyURL(mustParseURL(proxy.URL))}}
64+
resp, err := proxyClient.Do(req)
65+
if err != nil {
66+
t.Fatalf("request failed: %v", err)
67+
}
68+
_, _ = io.ReadAll(resp.Body)
69+
resp.Body.Close()
70+
71+
v := store.View(session.DefaultSessionID)
72+
if v == nil {
73+
t.Fatal("no session recorded")
74+
}
75+
var reqEv, respEv *pipeline.SessionEvent
76+
for i := range v.Events {
77+
e := &v.Events[i]
78+
if e.MCP == nil || e.MCP.Method != "tools/list" {
79+
continue
80+
}
81+
switch e.Phase {
82+
case pipeline.SessionRequest:
83+
reqEv = e
84+
case pipeline.SessionResponse:
85+
respEv = e
86+
}
87+
}
88+
if reqEv == nil || respEv == nil {
89+
t.Fatalf("missing req/resp events: req=%v resp=%v", reqEv != nil, respEv != nil)
90+
}
91+
92+
// Request side parsed (sanity).
93+
if reqEv.Invocations == nil || len(reqEv.Invocations.Outbound) == 0 {
94+
t.Errorf("request event has no mcp-parser invocation: %+v", reqEv.Invocations)
95+
}
96+
97+
// THE ASSERTION: the response was parsed into a result and recorded an
98+
// observe. Live cluster fails both.
99+
if respEv.MCP.Result == nil {
100+
t.Errorf("response MCP.Result not populated (parser never saw the SSE result)")
101+
}
102+
respObserved := respEv.Invocations != nil && len(respEv.Invocations.Outbound) > 0
103+
if !respObserved {
104+
t.Errorf("response event has NO mcp-parser invocation — reproduces the bug. invocations=%+v", respEv.Invocations)
105+
}
106+
}

authbridge/authlib/listener/forwardproxy/server.go

Lines changed: 12 additions & 15 deletions
Original file line numberDiff line numberDiff line change
@@ -307,16 +307,14 @@ func (s *Server) serveOutbound(w http.ResponseWriter, r *http.Request, isBridge
307307
Identity: pipeline.SnapshotIdentity(pctx),
308308
Host: pctx.Host,
309309
}
310-
// Record whenever ANY protocol-or-plugin context is present —
311-
// MCP/Inference (parser-emitted), Invocations (gate plugins like
312-
// jwt-validation/token-exchange), or plugin-public Plugins
313-
// entries. Earlier the gate was just MCP||Inference; widening
314-
// it ensures auth-only outbound traffic and pure observability
315-
// events show up in abctl. Don't narrow this back without
316-
// understanding why each clause is necessary.
317-
if ev.MCP != nil || ev.Inference != nil || ev.Invocations != nil || plugins != nil {
318-
s.Sessions.Append(sid, ev)
319-
}
310+
// Record EVERY message that reaches the pipeline — even when no
311+
// plugin acted and no parser matched (Invocations/MCP/Inference all
312+
// nil). The session API is an observability surface; a request the
313+
// pipeline saw but no plugin touched is still a network message the
314+
// operator wants to see (it carries Host, and the paired response
315+
// carries StatusCode). skip_hosts traffic never reaches here (the
316+
// !skipped guard above), so it stays suppressed by design.
317+
s.Sessions.Append(sid, ev)
320318
}
321319

322320
newAuth := pctx.Headers.Get("Authorization")
@@ -519,11 +517,10 @@ func (s *Server) recordOutboundResponseEvent(pctx *pipeline.Context, statusCode
519517
Error: pipeline.DeriveError(pctx),
520518
Duration: pipeline.DurationSince(pctx.StartedAt),
521519
}
522-
// Same widened gate as the request side — see the request-phase
523-
// comment for why each clause matters.
524-
if ev.MCP != nil || ev.Inference != nil || ev.Invocations != nil || plugins != nil {
525-
s.Sessions.Append(sid, ev)
526-
}
520+
// Always record — see the request-phase comment. This is what surfaces
521+
// responses no plugin acted on (e.g. a generic 404), carrying StatusCode
522+
// + Error even with empty invocations.
523+
s.Sessions.Append(sid, ev)
527524
}
528525

529526
// isEventStream reports whether a Content-Type header value names the

authbridge/authlib/listener/forwardproxy/server_test.go

Lines changed: 51 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -567,6 +567,57 @@ func TestRecordOutboundReject_SkipsWithoutInvocations(t *testing.T) {
567567
}
568568
}
569569

570+
// TestForwardProxy_RecordsMessageWithNoPluginActivity locks the Part A
571+
// behavior: a request/response that no plugin acted on (empty pipeline,
572+
// no parser match) is still recorded as two session events so abctl can
573+
// show every network message — not just the ones a plugin touched. The
574+
// response event carries the upstream status even though Invocations is
575+
// nil.
576+
func TestForwardProxy_RecordsMessageWithNoPluginActivity(t *testing.T) {
577+
store := session.New(5*time.Minute, 100, 0)
578+
defer store.Close()
579+
580+
backend := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, _ *http.Request) {
581+
w.WriteHeader(http.StatusNotFound)
582+
}))
583+
defer backend.Close()
584+
585+
// Empty pipeline: zero plugins, so no Invocations are ever appended.
586+
p, err := pipeline.New([]pipeline.Plugin{})
587+
if err != nil {
588+
t.Fatal(err)
589+
}
590+
srv := &Server{OutboundPipeline: pipeline.NewHolder(p), Sessions: store, Client: http.DefaultClient}
591+
proxy := httptest.NewServer(srv.Handler())
592+
defer proxy.Close()
593+
594+
req, _ := http.NewRequest("GET", backend.URL+"/missing", nil)
595+
proxyClient := &http.Client{Transport: &http.Transport{Proxy: http.ProxyURL(mustParseURL(proxy.URL))}}
596+
resp, err := proxyClient.Do(req)
597+
if err != nil {
598+
t.Fatalf("request failed: %v", err)
599+
}
600+
resp.Body.Close()
601+
if resp.StatusCode != http.StatusNotFound {
602+
t.Errorf("status = %d, want 404", resp.StatusCode)
603+
}
604+
605+
v := store.View(session.DefaultSessionID)
606+
if v == nil || len(v.Events) != 2 {
607+
t.Fatalf("expected 2 events (request + response) with no plugin activity, got %+v", v)
608+
}
609+
reqEv, respEv := v.Events[0], v.Events[1]
610+
if reqEv.Phase != pipeline.SessionRequest || reqEv.Invocations != nil {
611+
t.Errorf("request event = phase %v invocations %+v, want SessionRequest / nil", reqEv.Phase, reqEv.Invocations)
612+
}
613+
if respEv.Phase != pipeline.SessionResponse || respEv.StatusCode != http.StatusNotFound {
614+
t.Errorf("response event = phase %v status %d, want SessionResponse / 404", respEv.Phase, respEv.StatusCode)
615+
}
616+
if respEv.Invocations != nil {
617+
t.Errorf("response event invocations = %+v, want nil (no plugin acted)", respEv.Invocations)
618+
}
619+
}
620+
570621
// schemeCapturePlugin captures pctx.Scheme for the scheme-wiring
571622
// test below.
572623
type schemeCapturePlugin struct {

authbridge/authlib/listener/forwardproxy/transparent.go

Lines changed: 7 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -179,10 +179,14 @@ func (s *Server) recordTunnelOpened(pctx *pipeline.Context) {
179179
Plugins: plugins,
180180
Identity: pipeline.SnapshotIdentity(pctx),
181181
Host: pctx.Host,
182+
// Explicit opaque-tunnel marker so abctl can fold this CONNECT into
183+
// the decrypted inner request without inferring "tunnel" from shape.
184+
Tunnel: true,
182185
}
183-
if ev.Invocations != nil || plugins != nil {
184-
s.Sessions.Append(sid, ev)
185-
}
186+
// Always record the tunnel-open so passthrough/non-bridged tunnels (no
187+
// plugin activity) are still visible. For a TLS-bridged call abctl folds
188+
// this CONNECT event into the decrypted inner-request row.
189+
s.Sessions.Append(sid, ev)
186190
}
187191

188192
// tunnel bidirectionally copies between two connections until either side

authbridge/authlib/listener/forwardproxy/transparent_test.go

Lines changed: 25 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -8,8 +8,33 @@ import (
88

99
"github.com/kagenti/kagenti-extensions/authbridge/authlib/pipeline"
1010
"github.com/kagenti/kagenti-extensions/authbridge/authlib/plugins/plugintesting"
11+
"github.com/kagenti/kagenti-extensions/authbridge/authlib/session"
1112
)
1213

14+
// TestRecordTunnelOpened_SetsTunnelMarker locks the explicit producer marker:
15+
// a CONNECT / transparent-redirect tunnel-open is recorded with Tunnel=true so
16+
// consumers (abctl) fold it into the decrypted inner request without inferring
17+
// "tunnel" from host/extension shape.
18+
func TestRecordTunnelOpened_SetsTunnelMarker(t *testing.T) {
19+
store := session.New(5*time.Minute, 100, 0)
20+
defer store.Close()
21+
s := &Server{Sessions: store}
22+
23+
s.recordTunnelOpened(&pipeline.Context{Direction: pipeline.Outbound, Host: "example.com:443"})
24+
25+
v := store.View(session.DefaultSessionID)
26+
if v == nil || len(v.Events) != 1 {
27+
t.Fatalf("expected 1 tunnel-open event, got %+v", v)
28+
}
29+
ev := v.Events[0]
30+
if !ev.Tunnel {
31+
t.Error("tunnel-open event must have Tunnel=true")
32+
}
33+
if ev.Direction != pipeline.Outbound || ev.Phase != pipeline.SessionRequest {
34+
t.Errorf("tunnel-open = %v/%v, want Outbound/SessionRequest", ev.Direction, ev.Phase)
35+
}
36+
}
37+
1338
// HandleTransparentConn gates then blind-tunnels: with an allow-all pipeline it
1439
// must dial the recovered destination and copy bytes both ways, emitting no
1540
// proxy-protocol bytes of its own (the agent thinks it's talking to dst).

authbridge/authlib/listener/reverseproxy/finisher_test.go

Lines changed: 25 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -6,11 +6,27 @@ import (
66
"net/http/httptest"
77
"sync/atomic"
88
"testing"
9+
"time"
910

1011
"github.com/kagenti/kagenti-extensions/authbridge/authlib/pipeline"
1112
"github.com/kagenti/kagenti-extensions/authbridge/authlib/plugins/plugintesting"
1213
)
1314

15+
// waitSeen polls b until it's true, up to ~1s. OnFinish runs in the
16+
// reverse-proxy handler's deferred RunFinish, which fires only after the
17+
// streamed response (NewServer sets FlushInterval=-1) has already reached the
18+
// client — so http.Get can return before OnFinish has run. Poll rather than
19+
// read immediately, which otherwise races (flaky under -race).
20+
func waitSeen(b *atomic.Bool) bool {
21+
for i := 0; i < 1000; i++ {
22+
if b.Load() {
23+
return true
24+
}
25+
time.Sleep(time.Millisecond)
26+
}
27+
return false
28+
}
29+
1430
// finisherStub is a minimal Plugin + Finisher used by these tests to
1531
// observe OnFinish dispatch and the Outcome the listener derived.
1632
type finisherStub struct {
@@ -34,11 +50,13 @@ func (p *finisherStub) OnResponse(context.Context, *pipeline.Context) pipeline.A
3450
return pipeline.Action{Type: pipeline.Continue}
3551
}
3652
func (p *finisherStub) OnFinish(_ context.Context, pctx *pipeline.Context) {
37-
p.seen.Store(true)
3853
if o := pctx.Outcome(); o != nil {
3954
cp := *o
4055
p.outcome.Store(&cp)
4156
}
57+
// Store seen LAST so a reader that observes seen==true is guaranteed to
58+
// also see the outcome that was set just above.
59+
p.seen.Store(true)
4260
}
4361

4462
func pipelineWith(t *testing.T, plugins ...pipeline.Plugin) *pipeline.Holder {
@@ -73,7 +91,7 @@ func TestReverseProxy_Finisher_Allow(t *testing.T) {
7391
}
7492
resp.Body.Close()
7593

76-
if !f.seen.Load() {
94+
if !waitSeen(&f.seen) {
7795
t.Fatal("OnFinish did not fire")
7896
}
7997
o := f.outcome.Load()
@@ -133,12 +151,15 @@ func TestReverseProxy_Finisher_Deny(t *testing.T) {
133151
t.Errorf("HTTP status = %d, want 403", resp.StatusCode)
134152
}
135153

136-
if !before.seen.Load() {
154+
if !waitSeen(&before.seen) {
137155
t.Error("before-deny.OnFinish should have fired (OnRequest ran before denial)")
138156
}
139-
if !denier.seen.Load() {
157+
if !waitSeen(&denier.seen) {
140158
t.Error("denier.OnFinish should have fired (OnRequest ran and produced the deny)")
141159
}
160+
// before/denier have fired, so the single RunFinish dispatch is complete;
161+
// after-deny was never dispatched (its OnRequest never ran), so its
162+
// OnFinish must not have fired.
142163
if after.seen.Load() {
143164
t.Error("after-deny.OnFinish should NOT have fired (OnRequest never ran)")
144165
}

authbridge/authlib/listener/reverseproxy/server.go

Lines changed: 7 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -256,7 +256,9 @@ func (s *Server) handleRequest(w http.ResponseWriter, r *http.Request) {
256256
// as denials already do via recordInboundReject). The A2A-specific session
257257
// rekey in modifyResponse stays A2A-gated.
258258
plugins := pipeline.SnapshotPlugins(pctx.Extensions.Custom)
259-
if s.Sessions != nil && (pctx.Extensions.A2A != nil || pctx.Extensions.Invocations != nil || plugins != nil) {
259+
// Record every inbound request the pipeline saw, even with no plugin
260+
// activity (skip_hosts is N/A inbound).
261+
if s.Sessions != nil {
260262
sid := inboundSessionID(pctx)
261263
// Snapshot-copy the protocol extension and use the shared helpers
262264
// for plugin invocations / observability / identity. Mirrors what
@@ -378,7 +380,8 @@ func (s *Server) modifyResponse(resp *http.Response) error {
378380
// pipeline saw at this point (may be empty for streamed bodies),
379381
// but the status code and plugin invocations are always meaningful.
380382
plugins := pipeline.SnapshotPlugins(pctx.Extensions.Custom)
381-
if s.Sessions != nil && (pctx.Extensions.A2A != nil || pctx.Extensions.Invocations != nil || plugins != nil) {
383+
// Always pair every inbound request with a response row (carries StatusCode).
384+
if s.Sessions != nil {
382385
sid := inboundSessionID(pctx)
383386
s.Sessions.Append(sid, pipeline.SessionEvent{
384387
At: time.Now(),
@@ -513,9 +516,8 @@ func (s *Server) recordInboundResponseEvent(pctx *pipeline.Context, statusCode i
513516
return
514517
}
515518
plugins := pipeline.SnapshotPlugins(pctx.Extensions.Custom)
516-
if !(pctx.Extensions.A2A != nil || pctx.Extensions.Invocations != nil || plugins != nil) {
517-
return
518-
}
519+
// Always record the streaming response (carries StatusCode), even with
520+
// no plugin activity.
519521
sid := inboundSessionID(pctx)
520522
// Rekey default → contextId mirroring the buffered path's behavior;
521523
// streaming A2A message/stream may discover the contextId mid-stream.

0 commit comments

Comments
 (0)