Skip to content

Commit d4608a1

Browse files
authored
Remove duplicate log calls where global structured logger already covers the event (#2522)
Every significant event in 23+ files was being logged twice: once via a package-level `logXxx.Printf()` debug logger (stderr, `DEBUG=` controlled) and once via the global `logger.LogInfo/Warn/Error()` structured logger (always written to files). This created ~40 duplicate log call-pairs with no policy to guide which to use. ## Changes Removed 24 redundant local `logXxx.Printf()` calls across 6 files, keeping only the global structured call where both logged the same event: - **`internal/server/auth.go`** — Remove 3 `logAuth.Printf` calls for auth failed/success events already covered by `logger.LogErrorMd`/`LogInfo` - **`internal/launcher/launcher.go`** — Remove 9 `logLauncher.Printf` calls for `GetOrLaunch`/`GetOrLaunchForSession` events already covered by adjacent `logger.LogDebugWithServer`/`LogInfoWithServer`/`LogErrorWithServer` - **`internal/mcp/schema.go`** — Remove 4 `logSchema.Printf` calls for schema normalization outcomes already covered by `logger.LogWarn` - **`internal/mcp/connection.go`** — Remove 4 `logConn.Printf` calls for connection lifecycle events already covered by `logger.LogInfo`/`LogInfoWithServer` - **`internal/server/handlers.go`** — Remove 2 `logHandlers.Print/Printf` calls for `/close` endpoint events already covered by `logger.LogInfo`/`LogWarn` - **`internal/server/routed.go`** — Remove local `log := logger.New(logNamespace)` and `log.Printf` inside `rejectIfShutdown` closure; `logger.LogWarn` already covers the shutdown rejection **Before:** ```go logAuth.Printf("Authentication failed: invalid API key") logger.LogErrorMd("auth", "Authentication failed: invalid API key, remote=%s, path=%s", r.RemoteAddr, r.URL.Path) ``` **After:** ```go logger.LogErrorMd("auth", "Authentication failed: invalid API key, remote=%s, path=%s", r.RemoteAddr, r.URL.Path) ``` All debug-only `logXxx.Printf` calls with no global logger counterpart are preserved — they continue to serve development tracing via `DEBUG=namespace:*`. > [!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-build1349128381/b329/launcher.test /tmp/go-build1349128381/b329/launcher.test -test.testlogfile=/tmp/go-build1349128381/b329/testlog.txt -test.paniconexit0 -test.timeout=10m0s -test.v=true _.a 166736/b151/` (dns block) > - Triggering command: `/tmp/go-build3953803593/b333/launcher.test /tmp/go-build3953803593/b333/launcher.test -test.testlogfile=/tmp/go-build3953803593/b333/testlog.txt -test.paniconexit0 -test.timeout=10m0s --no�� g_.a 64/pkg/tool/linu-trimpath ache/go/1.25.8/x64/pkg/tool/linux_amd64/vet go ternal/fips140/d-unsafeptr=false x_amd64/cgo ache/go/1.25.8/x64/pkg/tool/linux_amd64/vet --no�� KRDG6iSQG x_amd64/cgo ache/go/1.25.8/x64/pkg/tool/linux_amd64/vet --local k/gh-aw-mcpg/gh--V=full 86_64/as ache/go/1.25.8/x64/pkg/tool/linu-buildtags` (dns block) > - `invalid-host-that-does-not-exist-12345.com` > - Triggering command: `/tmp/go-build1349128381/b314/config.test /tmp/go-build1349128381/b314/config.test -test.testlogfile=/tmp/go-build1349128381/b314/testlog.txt -test.paniconexit0 -test.timeout=10m0s -test.v=true mt-go@v0.1.7/for-n1 mt-go@v0.1.7/par--format=format:%H %ct %D 64/pkg/tool/linu--end-of-options -p github.com/model-o -lang=go1.25 64/pkg/tool/linu-trimpath ter-�� _.a 166736/b151/ de/node/bin/bash-lang=go1.25 -o /dev/null /tmp/cctRuc9T.s /usr/libexec/gcc/tmp/go-build1349128381/b175/vet.cfg` (dns block) > - Triggering command: `/tmp/go-build3953803593/b318/config.test /tmp/go-build3953803593/b318/config.test -test.testlogfile=/tmp/go-build3953803593/b318/testlog.txt -test.paniconexit0 -test.timeout=10m0s push�� aw-mcpg/internal/launcher/connection_pool.go .cfg util.test go --local 64/pkg/tool/linu/tmp/go-build1106856649/b085/vet.cfg util.test 3491�� 5762130/b248/_pkg_.a --scope docker-compose --property=Memor/opt/hostedtoolcache/go/1.25.8/x64/pkg/tool/linux_amd64/vet b/gh-aw-mcpg/int/tmp/go-build1106856649/b235/vet.cfg --property=MemoryHigh=170M docker-compose` (dns block) > - `nonexistent.local` > - Triggering command: `/tmp/go-build1349128381/b329/launcher.test /tmp/go-build1349128381/b329/launcher.test -test.testlogfile=/tmp/go-build1349128381/b329/testlog.txt -test.paniconexit0 -test.timeout=10m0s -test.v=true _.a 166736/b151/` (dns block) > - Triggering command: `/tmp/go-build3953803593/b333/launcher.test /tmp/go-build3953803593/b333/launcher.test -test.testlogfile=/tmp/go-build3953803593/b333/testlog.txt -test.paniconexit0 -test.timeout=10m0s --no�� g_.a 64/pkg/tool/linu-trimpath ache/go/1.25.8/x64/pkg/tool/linux_amd64/vet go ternal/fips140/d-unsafeptr=false x_amd64/cgo ache/go/1.25.8/x64/pkg/tool/linux_amd64/vet --no�� KRDG6iSQG x_amd64/cgo ache/go/1.25.8/x64/pkg/tool/linux_amd64/vet --local k/gh-aw-mcpg/gh--V=full 86_64/as ache/go/1.25.8/x64/pkg/tool/linu-buildtags` (dns block) > - `slow.example.com` > - Triggering command: `/tmp/go-build1349128381/b329/launcher.test /tmp/go-build1349128381/b329/launcher.test -test.testlogfile=/tmp/go-build1349128381/b329/testlog.txt -test.paniconexit0 -test.timeout=10m0s -test.v=true _.a 166736/b151/` (dns block) > - Triggering command: `/tmp/go-build3953803593/b333/launcher.test /tmp/go-build3953803593/b333/launcher.test -test.testlogfile=/tmp/go-build3953803593/b333/testlog.txt -test.paniconexit0 -test.timeout=10m0s --no�� g_.a 64/pkg/tool/linu-trimpath ache/go/1.25.8/x64/pkg/tool/linux_amd64/vet go ternal/fips140/d-unsafeptr=false x_amd64/cgo ache/go/1.25.8/x64/pkg/tool/linux_amd64/vet --no�� KRDG6iSQG x_amd64/cgo ache/go/1.25.8/x64/pkg/tool/linux_amd64/vet --local k/gh-aw-mcpg/gh--V=full 86_64/as ache/go/1.25.8/x64/pkg/tool/linu-buildtags` (dns block) > - `this-host-does-not-exist-12345.com` > - Triggering command: `/tmp/go-build1349128381/b338/mcp.test /tmp/go-build1349128381/b338/mcp.test -test.testlogfile=/tmp/go-build1349128381/b338/testlog.txt -test.paniconexit0 -test.timeout=10m0s -test.v=true assword=$GITHUB_-s assword=$GITHUB_-w ache/go/1.25.8/x-buildmode=exe --gdwarf-5 --64 -o ache/go/1.25.8/x-extld=gcc -E 166736/b193/_pkg_.a -m64 x_amd64/vet /tmp/go-build417bash g/x/net/http/htt/usr/bin/runc -fno-stack-prote--version x_amd64/vet` (dns block) > - Triggering command: `/tmp/go-build3953803593/b342/mcp.test /tmp/go-build3953803593/b342/mcp.test -test.testlogfile=/tmp/go-build3953803593/b342/testlog.txt -test.paniconexit0 -test.timeout=10m0s --no�� --noprofile u/13/cc1 .cfg --local 64/src/runtime/c-V=full cal/bin/bash ache/go/1.25.8/x64/pkg/tool/linux_amd64/vet` (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> <!-- START COPILOT CODING AGENT TIPS --> --- 💬 Send tasks to Copilot coding agent from [Slack](https://gh.io/cca-slack-docs) and [Teams](https://gh.io/cca-teams-docs) to turn conversations into code. Copilot posts an update in your thread when it's finished.
2 parents 628dc32 + 3463fac commit d4608a1

6 files changed

Lines changed: 0 additions & 24 deletions

File tree

internal/launcher/launcher.go

Lines changed: 0 additions & 9 deletions
Original file line numberDiff line numberDiff line change
@@ -64,14 +64,12 @@ func New(ctx context.Context, cfg *config.Config) *Launcher {
6464
// GetOrLaunch returns an existing connection or launches a new one
6565
func GetOrLaunch(l *Launcher, serverID string) (*mcp.Connection, error) {
6666
logger.LogDebugWithServer(serverID, "backend", "GetOrLaunch called for server: %s", serverID)
67-
logLauncher.Printf("GetOrLaunch called: serverID=%s", serverID)
6867

6968
// Check if already exists
7069
l.mu.RLock()
7170
if conn, ok := l.connections[serverID]; ok {
7271
l.mu.RUnlock()
7372
logger.LogDebugWithServer(serverID, "backend", "Reusing existing backend connection: %s", serverID)
74-
logLauncher.Printf("Reusing existing connection: serverID=%s", serverID)
7573
return conn, nil
7674
}
7775
l.mu.RUnlock()
@@ -85,15 +83,13 @@ func GetOrLaunch(l *Launcher, serverID string) (*mcp.Connection, error) {
8583
// Double-check after acquiring write lock
8684
if conn, ok := l.connections[serverID]; ok {
8785
logger.LogDebugWithServer(serverID, "backend", "Backend connection created by another goroutine: %s", serverID)
88-
logLauncher.Printf("Connection created by another goroutine: serverID=%s", serverID)
8986
return conn, nil
9087
}
9188

9289
// Get server config
9390
serverCfg, ok := l.config.Servers[serverID]
9491
if !ok {
9592
logger.LogErrorWithServer(serverID, "backend", "Backend server not found in config: %s", serverID)
96-
logLauncher.Printf("Server not found in config: serverID=%s", serverID)
9793
return nil, fmt.Errorf("server '%s' not found in config", serverID)
9894
}
9995
logLauncher.Printf("Retrieved server config: serverID=%s, type=%s", serverID, serverCfg.Type)
@@ -103,7 +99,6 @@ func GetOrLaunch(l *Launcher, serverID string) (*mcp.Connection, error) {
10399
logger.LogInfoWithServer(serverID, "backend", "Configuring HTTP MCP backend: %s, url=%s", serverID, serverCfg.URL)
104100
log.Printf("[LAUNCHER] Configuring HTTP MCP backend: %s", serverID)
105101
log.Printf("[LAUNCHER] URL: %s", serverCfg.URL)
106-
logLauncher.Printf("HTTP backend: serverID=%s, url=%s", serverID, serverCfg.URL)
107102

108103
// Create an HTTP connection
109104
conn, err := mcp.NewHTTPConnection(l.ctx, serverID, serverCfg.URL, serverCfg.Headers)
@@ -116,7 +111,6 @@ func GetOrLaunch(l *Launcher, serverID string) (*mcp.Connection, error) {
116111

117112
logger.LogInfoWithServer(serverID, "backend", "Successfully configured HTTP MCP backend: %s", serverID)
118113
log.Printf("[LAUNCHER] Successfully configured HTTP backend: %s", serverID)
119-
logLauncher.Printf("HTTP connection configured: serverID=%s", serverID)
120114

121115
l.connections[serverID] = conn
122116
return conn, nil
@@ -135,7 +129,6 @@ func GetOrLaunch(l *Launcher, serverID string) (*mcp.Connection, error) {
135129
// This is used for stateful stdio backends that require persistent connections
136130
func GetOrLaunchForSession(l *Launcher, serverID, sessionID string) (*mcp.Connection, error) {
137131
logger.LogDebugWithServer(serverID, "backend", "GetOrLaunchForSession called: server=%s, session=%s", serverID, sessionID)
138-
logLauncher.Printf("GetOrLaunchForSession called: serverID=%s, sessionID=%s", serverID, sessionID)
139132

140133
// Get server config first to determine backend type
141134
l.mu.RLock()
@@ -157,7 +150,6 @@ func GetOrLaunchForSession(l *Launcher, serverID, sessionID string) (*mcp.Connec
157150
// For stdio backends, check the session pool first
158151
if conn, exists := l.sessionPool.Get(serverID, sessionID); exists {
159152
logger.LogDebugWithServer(serverID, "backend", "Reusing session connection: server=%s, session=%s", serverID, sessionID)
160-
logLauncher.Printf("Reusing session connection: serverID=%s, sessionID=%s", serverID, sessionID)
161153
return conn, nil
162154
}
163155

@@ -171,7 +163,6 @@ func GetOrLaunchForSession(l *Launcher, serverID, sessionID string) (*mcp.Connec
171163
// Double-check after acquiring lock
172164
if conn, exists := l.sessionPool.Get(serverID, sessionID); exists {
173165
logger.LogDebugWithServer(serverID, "backend", "Session connection created by another goroutine: server=%s, session=%s", serverID, sessionID)
174-
logLauncher.Printf("Session connection created by another goroutine: serverID=%s, sessionID=%s", serverID, sessionID)
175166
return conn, nil
176167
}
177168

internal/mcp/connection.go

Lines changed: 0 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -76,7 +76,6 @@ type Connection struct {
7676
// NewConnection creates a new MCP connection using the official SDK
7777
func NewConnection(ctx context.Context, serverID, command string, args []string, env map[string]string) (*Connection, error) {
7878
logger.LogInfo("backend", "Creating new MCP backend connection, command=%s, args=%v", command, sanitize.SanitizeArgs(args))
79-
logConn.Printf("Creating new MCP connection: command=%s, args=%v", command, sanitize.SanitizeArgs(args))
8079
ctx, cancel := context.WithCancel(ctx)
8180

8281
// Create MCP client with logger
@@ -117,7 +116,6 @@ func NewConnection(ctx context.Context, serverID, command string, args []string,
117116
line := scanner.Text()
118117
sanitizedLine := sanitize.SanitizeString(line)
119118
logger.LogInfoWithServer(serverID, "backend", "[stderr] %s", sanitizedLine)
120-
logConn.Printf("[%s stderr] %s", serverID, sanitizedLine)
121119
}
122120
}()
123121

@@ -171,7 +169,6 @@ func NewConnection(ctx context.Context, serverID, command string, args []string,
171169
}
172170

173171
logger.LogInfoMd("backend", "Successfully connected to MCP backend server, command=%s", command)
174-
logConn.Printf("Successfully connected to MCP server: command=%s", command)
175172

176173
conn := &Connection{
177174
client: client,
@@ -200,7 +197,6 @@ func NewConnection(ctx context.Context, serverID, command string, args []string,
200197
// This ensures compatibility with all types of HTTP MCP servers.
201198
func NewHTTPConnection(ctx context.Context, serverID, url string, headers map[string]string) (*Connection, error) {
202199
logger.LogInfo("backend", "Creating HTTP MCP connection with transport fallback, url=%s", url)
203-
logConn.Printf("Creating HTTP MCP connection: url=%s", url)
204200
ctx, cancel := context.WithCancel(ctx)
205201

206202
// Create an HTTP client with appropriate timeouts

internal/mcp/schema.go

Lines changed: 0 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -17,7 +17,6 @@ func NormalizeInputSchema(schema map[string]interface{}, toolName string) map[st
1717
// If backend didn't provide a schema, use a default empty object schema
1818
// This allows the tool to be registered and clients will see it accepts any parameters
1919
if schema == nil {
20-
logSchema.Printf("Tool %s has nil schema, applying default empty object schema", toolName)
2120
logger.LogWarn("backend", "Tool schema normalized: %s - backend provided no inputSchema, using default empty object schema", toolName)
2221
return map[string]interface{}{
2322
"type": "object",
@@ -43,11 +42,9 @@ func NormalizeInputSchema(schema map[string]interface{}, toolName string) map[st
4342
normalized[k] = v
4443
}
4544
normalized["type"] = "object"
46-
logSchema.Printf("Tool %s schema normalized: added object type", toolName)
4745
return normalized
4846
}
4947
// Schema without type and without properties - assume it's an empty object schema
50-
logSchema.Printf("Tool %s has no type and no properties, using empty object schema", toolName)
5148
logger.LogWarn("backend", "Tool schema normalized: %s - schema missing type, assuming empty object schema", toolName)
5249
return map[string]interface{}{
5350
"type": "object",
@@ -80,7 +77,6 @@ func NormalizeInputSchema(schema map[string]interface{}, toolName string) map[st
8077
}
8178
normalized["properties"] = map[string]interface{}{}
8279

83-
logSchema.Printf("Tool %s schema normalized: added empty properties field", toolName)
8480
return normalized
8581
}
8682

internal/server/auth.go

Lines changed: 0 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -45,7 +45,6 @@ func authMiddleware(apiKey string, next http.HandlerFunc) http.HandlerFunc {
4545
authHeader := r.Header.Get("Authorization")
4646

4747
if authHeader == "" {
48-
logAuth.Printf("Authentication failed: missing Authorization header")
4948
// Spec 7.1: Missing token returns 401
5049
logger.LogErrorMd("auth", "Authentication failed: missing Authorization header, remote=%s, path=%s", r.RemoteAddr, r.URL.Path)
5150
logRuntimeError("authentication_failed", "missing_auth_header", r, nil)
@@ -55,14 +54,12 @@ func authMiddleware(apiKey string, next http.HandlerFunc) http.HandlerFunc {
5554

5655
// Spec 7.1: Authorization header must contain API key directly (not Bearer scheme)
5756
if authHeader != apiKey {
58-
logAuth.Printf("Authentication failed: invalid API key")
5957
logger.LogErrorMd("auth", "Authentication failed: invalid API key, remote=%s, path=%s", r.RemoteAddr, r.URL.Path)
6058
logRuntimeError("authentication_failed", "invalid_api_key", r, nil)
6159
http.Error(w, "Unauthorized: invalid API key", http.StatusUnauthorized)
6260
return
6361
}
6462

65-
logAuth.Printf("Authentication successful")
6663
logger.LogInfo("auth", "Authentication successful, remote=%s, path=%s", r.RemoteAddr, r.URL.Path)
6764
// Token is valid, proceed to handler
6865
next(w, r)

internal/server/handlers.go

Lines changed: 0 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -35,7 +35,6 @@ func handleOAuthDiscovery() http.Handler {
3535
func handleClose(unifiedServer *UnifiedServer) http.Handler {
3636
logHandlers.Print("Creating close handler")
3737
return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
38-
logHandlers.Printf("Close request received: remote=%s, method=%s, path=%s", r.RemoteAddr, r.Method, r.URL.Path)
3938
log.Printf("[%s] %s %s", r.RemoteAddr, r.Method, r.URL.Path)
4039
logger.LogInfo("shutdown", "Close endpoint called, remote=%s", r.RemoteAddr)
4140

@@ -48,7 +47,6 @@ func handleClose(unifiedServer *UnifiedServer) http.Handler {
4847

4948
// Check if already closed (idempotency - spec 5.1.3)
5049
if unifiedServer.IsShutdown() {
51-
logHandlers.Print("Gateway already shutdown, returning 410 Gone")
5250
logger.LogWarn("shutdown", "Close endpoint called but gateway already closed, remote=%s", r.RemoteAddr)
5351
writeJSONResponse(w, http.StatusGone, map[string]interface{}{
5452
"error": "Gateway has already been closed",

internal/server/routed.go

Lines changed: 0 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -20,10 +20,8 @@ var logRouted = logger.New("server:routed")
2020
// Per spec 5.1.3: "Immediately reject any new RPC requests to /mcp/{server-name} endpoints with HTTP 503"
2121
// The logNamespace parameter is used to create a logger for debug output specific to the call site.
2222
func rejectIfShutdown(unifiedServer *UnifiedServer, next http.Handler, logNamespace string) http.Handler {
23-
log := logger.New(logNamespace)
2423
return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
2524
if unifiedServer.IsShutdown() {
26-
log.Printf("Rejecting request during shutdown: remote=%s, method=%s, path=%s", r.RemoteAddr, r.Method, r.URL.Path)
2725
logger.LogWarn("shutdown", "Request rejected during shutdown, remote=%s, path=%s", r.RemoteAddr, r.URL.Path)
2826
writeJSONResponse(w, http.StatusServiceUnavailable, json.RawMessage(shutdownErrorJSON))
2927
return

0 commit comments

Comments
 (0)