Skip to content

Commit ac8733a

Browse files
authored
Refactor SendRequestWithServerID to use a single inbound response logging path (#4054)
`SendRequestWithServerID` had repeated marshal+log response blocks across transport branches, creating a maintainability hotspot and risk of branch-level drift in logging behavior. This change centralizes that logic into one helper while preserving existing call-site behavior. - **What changed** - Added `logInboundRPCResponseFromResult(...)` in `internal/mcp/connection.go` to: - marshal `*Response` (when non-nil), - call `logInboundRPCResponse(...)`, - return `(result, err)` unchanged. - Updated `SendRequestWithServerID` to use the helper for its return path instead of duplicating response logging logic inline. - **Why this matters** - Removes copy-pasted logging logic from transport handling flow. - Makes future changes to inbound response logging single-point edits. - **Targeted coverage added** - New tests in `internal/mcp/connection_logging_test.go` validate helper pass-through behavior for: - non-nil response + non-nil error, - nil response + nil error. ```go func logInboundRPCResponseFromResult(serverID string, result *Response, err error, shouldAttachTags bool, snapshot *AgentTagsSnapshot) (*Response, error) { var responsePayload []byte if result != nil { responsePayload, _ = json.Marshal(result) } logInboundRPCResponse(serverID, responsePayload, err, shouldAttachTags, snapshot) return result, err } ``` > [!WARNING] > > <details> > <summary>Firewall rules blocked me from connecting to one or more addresses (expand for details)</summary> > > #### I tried to connect to the following addresses, but was blocked by firewall rules: > > - `example.com` > - Triggering command: `/tmp/go-build2522761549/b510/launcher.test /tmp/go-build2522761549/b510/launcher.test -test.testlogfile=/tmp/go-build2522761549/b510/testlog.txt -test.paniconexit0 -test.timeout=10m0s -test.v=true ache/go/1.25.8/x-errorsas .cfg 64/pkg/tool/linu-nilfunc -I /tmp/go-build252-atomic -I 64/pkg/tool/linu-buildtags -o idi.go racket.go x_amd64/compile -p flag -lang=go1.25 x_amd64/compile` (dns block) > - Triggering command: `/tmp/go-build3233101705/b514/launcher.test /tmp/go-build3233101705/b514/launcher.test -test.testlogfile=/tmp/go-build3233101705/b514/testlog.txt -test.paniconexit0 -test.timeout=10m0s -uns�� -unreachable=false /tmp/go-build2522761549/b245/vet.cfg x_amd64/vet -c=4 -nolocalimports -importcfg x_amd64/vet -ato�� -bool -buildtags x_amd64/vet -errorsas 0832 -nilfunc x_amd64/vet` (dns block) > - `invalid-host-that-does-not-exist-12345.com` > - Triggering command: `/tmp/go-build2522761549/b492/config.test /tmp/go-build2522761549/b492/config.test -test.testlogfile=/tmp/go-build2522761549/b492/testlog.txt -test.paniconexit0 -test.timeout=10m0s -test.v=true` (dns block) > - Triggering command: `/tmp/go-build3233101705/b496/config.test /tmp/go-build3233101705/b496/config.test -test.testlogfile=/tmp/go-build3233101705/b496/testlog.txt -test.paniconexit0 -test.timeout=10m0s ortc�� pkg/mod/google.golang.org/[email protected]/internal/proxyattributes/-errorsas stmain.go x_amd64/vet --gdwarf-5 --64 -o x_amd64/vet -o 2761549/b492/config.test -trimpath x_amd64/vet -p golang.org/x/tex--norc -lang=go1.25 x_amd64/vet` (dns block) > - `nonexistent.local` > - Triggering command: `/tmp/go-build2522761549/b510/launcher.test /tmp/go-build2522761549/b510/launcher.test -test.testlogfile=/tmp/go-build2522761549/b510/testlog.txt -test.paniconexit0 -test.timeout=10m0s -test.v=true ache/go/1.25.8/x-errorsas .cfg 64/pkg/tool/linu-nilfunc -I /tmp/go-build252-atomic -I 64/pkg/tool/linu-buildtags -o idi.go racket.go x_amd64/compile -p flag -lang=go1.25 x_amd64/compile` (dns block) > - Triggering command: `/tmp/go-build3233101705/b514/launcher.test /tmp/go-build3233101705/b514/launcher.test -test.testlogfile=/tmp/go-build3233101705/b514/testlog.txt -test.paniconexit0 -test.timeout=10m0s -uns�� -unreachable=false /tmp/go-build2522761549/b245/vet.cfg x_amd64/vet -c=4 -nolocalimports -importcfg x_amd64/vet -ato�� -bool -buildtags x_amd64/vet -errorsas 0832 -nilfunc x_amd64/vet` (dns block) > - `slow.example.com` > - Triggering command: `/tmp/go-build2522761549/b510/launcher.test /tmp/go-build2522761549/b510/launcher.test -test.testlogfile=/tmp/go-build2522761549/b510/testlog.txt -test.paniconexit0 -test.timeout=10m0s -test.v=true ache/go/1.25.8/x-errorsas .cfg 64/pkg/tool/linu-nilfunc -I /tmp/go-build252-atomic -I 64/pkg/tool/linu-buildtags -o idi.go racket.go x_amd64/compile -p flag -lang=go1.25 x_amd64/compile` (dns block) > - Triggering command: `/tmp/go-build3233101705/b514/launcher.test /tmp/go-build3233101705/b514/launcher.test -test.testlogfile=/tmp/go-build3233101705/b514/testlog.txt -test.paniconexit0 -test.timeout=10m0s -uns�� -unreachable=false /tmp/go-build2522761549/b245/vet.cfg x_amd64/vet -c=4 -nolocalimports -importcfg x_amd64/vet -ato�� -bool -buildtags x_amd64/vet -errorsas 0832 -nilfunc x_amd64/vet` (dns block) > - `this-host-does-not-exist-12345.com` > - Triggering command: `/tmp/go-build2522761549/b519/mcp.test /tmp/go-build2522761549/b519/mcp.test -test.testlogfile=/tmp/go-build2522761549/b519/testlog.txt -test.paniconexit0 -test.timeout=10m0s -test.v=true 1.5.0/internal/xcontext/xcontext.go 4BJUeiabknHIHNszrg x_amd64/compile -p e/otlptracehttp//usr/bin/runc -lang=go1.25 x_amd64/compile -o g_.a 2761549/b165/ x_amd64/vet -p hash/fnv -lang=go1.25 x_amd64/vet` (dns block) > - Triggering command: `/tmp/go-build1064564734/b001/mcp.test /tmp/go-build1064564734/b001/mcp.test -test.testlogfile=/tmp/go-build1064564734/b001/testlog.txt -test.paniconexit0 -test.timeout=10m0s -uns�� 2761549/b402/_pkg_.a /tmp/go-build2522761549/b126/vet-ifaceassert .cfg --global g/grpc/mem 64/bin/bash ache/go/1.25.8/x64/pkg/tool/linu-tests -qui�� ppFW/Fi3uUr-n6b91NPffppFW k/gh-aw-mcpg/gh-aw-mcpg/internal/oidc/provider.gmain x_amd64/link . -imultiarch x86_64-linux-gnu x_amd64/link` (dns block) > > If you need me to access, download, or install something from one of these locations, you can either: > > - Configure [Actions setup steps](https://gh.io/copilot/actions-setup-steps) to set up my environment, which run before the firewall is enabled > - Add the appropriate URLs or hosts to the custom allowlist in this repository's [Copilot coding agent settings](https://github.com/github/gh-aw-mcpg/settings/copilot/coding_agent) (admins only) > > </details>
2 parents 52f30ba + 7d27235 commit ac8733a

2 files changed

Lines changed: 77 additions & 8 deletions

File tree

internal/mcp/connection.go

Lines changed: 13 additions & 8 deletions
Original file line numberDiff line numberDiff line change
@@ -444,6 +444,18 @@ func logInboundRPCResponse(serverID string, payload []byte, err error, shouldAtt
444444
}
445445
}
446446

447+
// logInboundRPCResponseFromResult attempts to marshal a response payload for logging,
448+
// silently ignores marshal failures, logs the inbound response, and returns the
449+
// original result and error unchanged.
450+
func logInboundRPCResponseFromResult(serverID string, result *Response, err error, shouldAttachTags bool, snapshot *AgentTagsSnapshot) (*Response, error) {
451+
var responsePayload []byte
452+
if result != nil {
453+
responsePayload, _ = json.Marshal(result)
454+
}
455+
logInboundRPCResponse(serverID, responsePayload, err, shouldAttachTags, snapshot)
456+
return result, err
457+
}
458+
447459
// SendRequest sends a JSON-RPC request and waits for the response
448460
// The serverID parameter is used for logging to associate the request with a backend server
449461
func (c *Connection) SendRequest(method string, params interface{}) (*Response, error) {
@@ -481,14 +493,7 @@ func (c *Connection) SendRequestWithServerID(ctx context.Context, method string,
481493
result, err = c.callSDKMethod(method, params)
482494
}
483495

484-
// Log the response from backend server
485-
var responsePayload []byte
486-
if result != nil {
487-
responsePayload, _ = json.Marshal(result)
488-
}
489-
logInboundRPCResponse(serverID, responsePayload, err, shouldAttachAgentTags, snapshot)
490-
491-
return result, err
496+
return logInboundRPCResponseFromResult(serverID, result, err, shouldAttachAgentTags, snapshot)
492497
}
493498

494499
// callSDKMethod calls the appropriate SDK method based on the method name
Lines changed: 64 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,64 @@
1+
package mcp
2+
3+
import (
4+
"bufio"
5+
"encoding/json"
6+
"errors"
7+
"os"
8+
"path/filepath"
9+
"testing"
10+
11+
"github.com/github/gh-aw-mcpg/internal/logger"
12+
"github.com/stretchr/testify/assert"
13+
"github.com/stretchr/testify/require"
14+
)
15+
16+
func TestLogInboundRPCResponseFromResult_LogsMarshaledResponseAndReturnsResultAndError(t *testing.T) {
17+
require := require.New(t)
18+
assert := assert.New(t)
19+
tmpDir := t.TempDir()
20+
logDir := filepath.Join(tmpDir, "logs")
21+
22+
require.NoError(logger.InitJSONLLogger(logDir, "rpc-messages.jsonl"))
23+
t.Cleanup(func() {
24+
require.NoError(logger.CloseJSONLLogger())
25+
})
26+
27+
expectedErr := errors.New("expected error")
28+
expectedResult := &Response{
29+
JSONRPC: "2.0",
30+
ID: 1,
31+
Result: []byte(`{"ok":true}`),
32+
}
33+
34+
result, err := logInboundRPCResponseFromResult("test-server", expectedResult, expectedErr, false, nil)
35+
36+
assert.Same(expectedResult, result)
37+
assert.ErrorIs(err, expectedErr)
38+
39+
logFile, err := os.Open(filepath.Join(logDir, "rpc-messages.jsonl"))
40+
require.NoError(err)
41+
defer logFile.Close()
42+
43+
scanner := bufio.NewScanner(logFile)
44+
require.True(scanner.Scan(), "expected a JSONL entry to be logged")
45+
46+
var entry logger.JSONLRPCMessage
47+
require.NoError(json.Unmarshal([]byte(scanner.Text()), &entry))
48+
assert.Equal(string(logger.RPCDirectionInbound), entry.Direction)
49+
assert.Equal(string(logger.RPCMessageResponse), entry.Type)
50+
assert.Equal("test-server", entry.ServerID)
51+
assert.Equal(expectedErr.Error(), entry.Error)
52+
assert.JSONEq(`{"jsonrpc":"2.0","id":1,"result":{"ok":true}}`, string(entry.Payload))
53+
assert.False(scanner.Scan(), "expected exactly one JSONL entry")
54+
require.NoError(scanner.Err())
55+
}
56+
57+
func TestLogInboundRPCResponseFromResult_AllowsNilResult(t *testing.T) {
58+
assert := assert.New(t)
59+
60+
result, err := logInboundRPCResponseFromResult("test-server", nil, nil, false, nil)
61+
62+
assert.Nil(result)
63+
assert.NoError(err)
64+
}

0 commit comments

Comments
 (0)